Трасування з .NET додатків в Azure

Підписуйтеся на Telegram-канал «DOU #tech», щоб не пропустити нові технічні статті

Усім привіт, на зв’язку Вова Вердиш, у цій статті хотів би поговорити про трасування з .NET додатків. Трасування — це один з трьох стовпів телеметрії. Звернемося до енциклопедичного значення цього терміну, тобто, до «Вікіпедії»:

Телеметрія (від грец. τῆλε «далеко» + μέτρεω — «вимірюю») — галузь науки і техніки, що займається питаннями розробки та експлуатації телеметричних систем — комплексу автоматизованих засобів, що забезпечують отримання, перетворення, передачу по каналу зв’язку, прийом, обробку та реєстрацію вимірювальної (телеметричної) інформації та інформації про різні події з метою контролю на відстані різних об’єктів та процесів.

З академічної точки зору, напевно, все чітко та зрозуміло. З погляду простої людини (мене, наприклад) — не дуже. Зрозуміло, що є якісь вимірювальні дані, зрозуміло, що є мета контролю за чимось, але, як і раніше, немає чіткого уявлення, що тут відбувається.

Що таке телеметрія у контексті розробки програмного забезпечення

Дуже влучний опис, на мій погляд, звучить так: телеметрія — це якісь дані, що виходять із системи, про її поведінку; до цих даних належать трасування, метрики, журнали. Взяв я цей опис звідси, в оригіналі він звучить так:

Telemetry refers to data emitted from a system, about its behavior. The data can come in the form of Traces, Metrics, and Logs.

До того, як я побачив Azure, я працював з додатками, які складали логи в Elasticsearch, які можна було дивитися через Kibana. Це класна штука. Коли я почав працювати з Azure, одне з перших питань в мене було: «А де тут логи?».

Application Insights

В Azure є спеціальний сервіс для збору та відображення телеметрії — Application Insights. Там зберігається все: і трасування, і метрики, і логи. Коли я вперше туди потрапив, я подумав: «Погань якась». Ця думка була в моїй голові якийсь час. А потім я побачив «це»:

Раніше я нічого такого не бачив. Я закохався у це. На цій картинці ми бачимо все, що в нас сталося в рамках «транзакції». До нас залетів вхідний http-запит, обробка цього вхідного запиту складалася зі звернення до БД, вихідного http-виклику до Google, розміщення повідомлення в Service Bus (черга в Azure), вичитування повідомлення з Service Bus.

Причому вичитування повідомлення з черги відбувається вже після того, як вхідний http-запит завершився. На цій картинці цього не видно, але я це знаю, тому що це мій код. В рамках «транзакції» не має значення, чи відбулось щось в рамках одного запита, чи ні.

Хоча вся ця штука і називається «end-to-end transaction», я беру слово «транзакція» в лапки, щоб ніхто раптом не подумав, що це має якесь відношення до БД. Мені здається, для цієї штуки могли б вигадати інший, більш відповідний термін. «Траса» (від слова трасування), «операція» або щось на зразок того, на мій погляд, підійшло б краще. Але «trace»-ом в Azure вирішили назвати логи, тож маємо, що маємо. Ну і грець з ним.

Подивімося детальніше на деякі елементи нашої «транзакції».

Всі елементи мають ряд загальних реквізитів, таких як, наприклад, час події, тривалість, ім’я, тип, службові ідентифікатори. Але кожен з них може мати щось своє. На зображенні вище — вхідний http-запит. Ми бачимо, що він був успішний (бачимо код відповіді 200), бачимо, куди саме був цей запит та якого типу він був.

На зображенні нижче — SQL-запит. І це при тому, що я використовую EntityFramework, а не «сирі запити».

Один з приємних моментів полягає в тому, що для того, щоб отримати це, нам не потрібно сильно напружуватися.

Як мені отримати трасування для свого додатка

Нагадаю свій сценарій: вхідний http-запит, звернення до БД, http-запит до Google, запис повідомлення в чергу, вичитування повідомлення з черги.

Є кілька способів, як можна почати писати трасування. Варіант перший — це використання Application Insights SDK. Підключаємо пакет Microsoft.ApplicationInsights.AspNetCore та конфігуруємо запис трасувань:

builder.Services.AddApplicationInsightsTelemetry();
builder.Services.ConfigureTelemetryModule<DependencyTrackingTelemetryModule>((module, o) =>
{
	module.EnableSqlCommandTextInstrumentation = true; // щоб SQL текст запитів було включено в трасування
});

Це все, що треба для того, щоб побачити таку красу:

Інший варіант — використовувати OpenTelemetry .NET. OpenTelemetry — це специфікація, розроблена Google ще з якоюсь компанією (здається, це прямо в них на сайті десь було написано; я читав колись, але зараз знайти не зміг). Є багато реалізацій цієї специфікації, розроблених під різні мови та платформи. OpenTelemetry .NET — це реалізація цієї специфікації на .NET.

Підключаємо ряд пакетів з набору OpenTelemetry:

OpenTelemetry.Extensions.Hosting, OpenTelemetry.Instrumentation.AspNetCore, OpenTelemetry.Instrumentation.Http, OpenTelemetry.Instrumentation.SqlClient, і оскільки ми хочемо все це побачити в Azure, підключаємо ще відповідний експортер Azure.Monitor.OpenTelemetry.Exporter.

Конфігуруємо це все:

builder.Services.AddOpenTelemetryTracing(tracingBuilder =>
{
	tracingBuilder.AddAzureMonitorTraceExporter(o =>
	{
		o.ConnectionString = configuration.GetValue<string>("ApplicationInsights:ConnectionString");
	});
	tracingBuilder.AddAspNetCoreInstrumentation();
	tracingBuilder.AddHttpClientInstrumentation();
	tracingBuilder.AddSqlClientInstrumentation(opt =>
	{
		opt.SetDbStatementForText = true; // якщо хочему SQL тексти додати в трасування
	});
});

У результаті бачимо дуже схожу красу:

Різниця в порівнянні з першим варіантом у тому, що в цьому випадку ми не маємо трасування для Service Bus. Формат рядка вхідного http-запиту я за різницю не вважаю. Наразі, коли я пишу ці літери, офіційного інструменту для запису трасувань ServiceBus немає. Можливо, є неофіційні, я не шукав. За бажання, звичайно, можна і самому написати.

То що мені обрати: Application Insights SDK або OpenTelemetry .NET?

OpenTelemetry — це майбутнє телеметрії, в тому числі для .NET додатків. Але зараз під .NET для Azure реалізовано не все те, що нам хотілося б. Якщо чесно, я не розумію, чому в Microsoft ще не реалізували все, що треба, при тому, що вони самі кажуть, що Application Insights SDK зараз не розвивається, що майбутнє за OpenTelemetry. На цю мить немає повноцінного експортера в Azure для OpenTelemetry. Ось що говорить Microsoft:

Carefully consider whether this preview is right for you. It enables distributed tracing only and excludes:

• Metrics API (like custom metrics and pre-aggregated metrics).
• Live Metrics.
• Logging API (like console logs and logging libraries).
• Autocapture of unhandled exceptions.
• Profiler.
• Snapshot Debugger.
• Offline disk storage and retry logic.
• Azure Active Directory authentication.
• Sampling.
• Autopopulation of Cloud Role Name and Cloud Role Instance in Azure environments.
• Autopopulation of User ID and Authenticated User ID when you use the Application Insights JavaScript SDK.
• Autopopulation of User IP (to determine location attributes).
• Ability to override Operation Name.
• Ability to manually set User ID or Authenticated User ID.
• Propagating Operation Name to Dependency Telemetry.
• Instrumentation libraries support on Azure Functions.

If you require a full-feature experience, use the existing Application Insights ASP.NET or ASP.NET Core SDK until the OpenTelemetry-based offering matures.

Якщо чесно, я сам не розумію, про що частина з описаних обмежень, або я це і так не використовую. Якщо продовжити говорити на чистоту, то я не до кінця розумію, що вже вміє OpenTelemetry, а що ще ні. Що у мене вийшло з OpenTelemetry в Azure:

• запис трасувань; хоча ASP.NET Core SDK з коробки вміє писати більше трасувань, пов’язаних з Azure, але для OpenTelemetry, наприклад, вже є розширення, які вміють збирати метрики з компонентів, не пов’язаних з Azure, наприклад MassTransit, MySQL, Elasticsearch;
• логи пишуться; не знаю, що означає 3 пункт зі списку обмежень вище, можливо, цей список застарів, а можливо він означає щось, що я не розумію;
• метрики пишуться; правда, якщо говорити, наприклад, про метрики середовища виконання, то ASP.NET Core SDK, схоже, дозволяє з коробки писати їх більше, ніж те, що дозволяє пакет для OpenTelemetry; у випадку з ASP.NET Core SDK ми самостійно вказуємо метрики, які ми хочемо писати, а які ні; у випадку з OpenTelemetry воно пише набір метрик, який закодовано у бібліотеці, без можливості конфігурації.

На цю мить у мене до OpenTelemetry багато питань. «Питань» не в плані «А що це за херня у вас тут?», «А от так навіщо робити?», а в плані, що я не знаю як, використовуючи її, не втратити нічого з того, що зараз нам дає ASP.NET Core SDK. Але ж ви пам’ятаєте, що я використовую Azure? Якщо у вас не Azure, то, можливо, вам варто подивитися у бік OpenTelemetry.

«Навіщо нам вся ця маячня з телеметрією? Ти ж про трасування обіцяв»

Про трасування, отже про трасування. Швидше за все, вас може цікавити ще одне питання: а як мені щось своє додати в трасування? Оскільки я використовую ASP.NET Core SDK, то покажу на його прикладі.

Сценарій: у мене є якесь завдання, яке виконується кожні Х хвилин, воно вибирає якісь ID з бази даних, робить якісь http-запити та складає щось назад у БД. Якщо ми нічого спеціально робити не будемо, ми побачимо і запити до БД, і http-запити, але вони будуть самі по собі. А я хочу бачити, що все це відбувається в рамках чогось, в цьому випадку, в рамках цього завдання.

Ключовим елементом у трасуванні сучасних .NET додатків є Activity. Microsoft описує цей клас наступним чином: Represents an operation with context to be used for logging. Я б описав це так: Represents an operation with context to be used for tracing. Характерними ознаками операції є час початку та час закінчення. У елемента лога є тільки дата події, в той час як у трасування є час початку і час закінчення операції. Але Microsoft, напевно, видніше.

Теоретично, ми могли б не використовувати Activity у своєму додатку. Але якби ми розробляли бібліотеку і хотіли виставити якісь свої активності для користувача бібліотеки, то я сказав би, що це найбільш пристойний варіант для нас сьогодні. Це абстракція, яка дозволяє відв’язати запис трасувань від конкретного сервісу для їх зберігання та візуалізації. Зроблено це все розумно, і якщо, наприклад, ви виставили якусь активність у своєму коді, але ніхто не зацікавлений у ній, то накладних витрат при цьому практично ніяких не буде.

Насамперед нам потрібно у своєму завданні створити активність. Для цього зручно використовувати ActivitySource. Зазвичай ActivitySource оголошується статичним полем, йому в конструктор передається ім’я джерела активності. Джерело активності нам знадобиться далі, коли ми захочемо слухати ці активності.

private static ActivitySource _source = new ActivitySource(ActivitySourceName);
//…
var activity = _source.StartActivity(“The operation name of the activity”);

Activity є IDisposable. Тому якщо ви запускаєте та зупиняється активність усередині одного методу, ви можете використовувати using:

using(var activity = _source.StartActivity(“The operation name of the activity”))
{
	// …
}

Використання using зробить код читабельнішим, плюс ця конструкція виконає за вас перевірку на null і викличе Dispose тільки в тому випадку, якщо ваша activity не null. А activity буде null у тому випадку, коли немає жодного слухача.

Активність є, але сама собою вона нікуди не потрапить. Код вище дасть можливість якомусь іншому коду у вашому додатку підписатися та отримувати повідомлення, коли активність стартує і зупиняється. Тому тепер нам потрібно зробити слухача цієї активності, який при її завершенні писатиме її в Azure. Запис будь-яких елементів телеметрії Azure ми будемо робити за допомогою TelemetryClient.

За одним з посилань вище ви можете почитати, як записувати будь-які елементи телеметрії в термінах Azure. У моєму випадку я вирішив, що мої елементи телеметрії — це Dependency. Я зробив собі такий клас:

public class ApplicationInsightsActivityToDependencyExporter: IApplicationInsightsActivityExporter
{
	private readonly TelemetryClient _telemetryClient;
	private readonly string _activitySourceName;
	private readonly Func<ApplicationInsightsActivityToDependencyExporter, string> _dependencyTypeNameGetter;
	private readonly Func<ApplicationInsightsActivityToDependencyExporter, string>? _dataGetter;

	public ApplicationInsightsActivityToDependencyExporter(
		TelemetryConfiguration telemetryConfiguration,
		string activitySourceName,
		Func<ApplicationInsightsActivityToDependencyExporter, string> dependencyTypeNameGetter,
		Func<ApplicationInsightsActivityToDependencyExporter, string> dataGetter = null!
	)
	{
		_telemetryClient = new TelemetryClient(telemetryConfiguration);

		_activitySourceName = activitySourceName;
		_dependencyTypeNameGetter = dependencyTypeNameGetter;
		_dataGetter = dataGetter;

		var listener = new ActivityListener
		{
			ShouldListenTo = activitySource => activitySource.Name == _activitySourceName,
			Sample = (ref ActivityCreationOptions<ActivityContext> _) => ActivitySamplingResult.AllData,
			ActivityStarted = ActivityStarted,
			ActivityStopped = ActivityStopped,
		};

		ActivitySource.AddActivityListener(listener);
		
	}

	protected virtual void ActivityStarted(Activity activity)
	{

	}

	protected virtual void ActivityStopped(Activity activity)
	{
		var dependencyTypeName = _dependencyTypeNameGetter(this);
		var data = _dataGetter?.Invoke(this) ?? $"Start time {activity.StartTimeUtc} - Stop time {DateTime.UtcNow}";

		DependencyTelemetry dependencyTelemetry = new DependencyTelemetry
		(
			dependencyTypeName,
			activity.Source.Name,
			activity.OperationName,
			data
		);
		
		dependencyTelemetry.Success = activity.Status != ActivityStatusCode.Error;
		dependencyTelemetry.Duration = activity.Duration;

		if (!string.IsNullOrEmpty(activity.StatusDescription))
			dependencyTelemetry.Properties["status-description"] = activity.StatusDescription;

		if (activity.IdFormat == ActivityIdFormat.W3C)
		{
			dependencyTelemetry.Id = activity.SpanId.ToHexString();
			dependencyTelemetry.Context.Operation.Id = activity.TraceId.ToHexString();
		}
		else
		{
			dependencyTelemetry.Id = activity.Id;
			dependencyTelemetry.Context.Operation.Id = activity.RootId;
		}

		dependencyTelemetry.Context.Operation.ParentId = activity.Parent?.SpanId.ToHexString();

		foreach (var keyValuePair in activity.Tags)
		{
			if (!dependencyTelemetry.Properties.ContainsKey(keyValuePair.Key))
				dependencyTelemetry.Properties[keyValuePair.Key] = keyValuePair.Value;
		}

		foreach (var keyValuePair in activity.Baggage)
		{
			if (!dependencyTelemetry.Properties.ContainsKey(keyValuePair.Key))
				dependencyTelemetry.Properties[keyValuePair.Key] = keyValuePair.Value;
		}

		dependencyTelemetry.Context.Operation.Name = activity.OperationName;

		_telemetryClient.TrackDependency(dependencyTelemetry);
	}
}

Декілька коментарів:

• для прослуховування активності використовується клас ActivityListener;
• обробник ActivityStarted я не використовую; я навіть не можу вигадати, для чого його можна було б використати з користю; але, напевно, є якісь сценарії, коли при старті активності треба щось своє зробити;
• інтерфейс IApplicationInsightsActivityExporter порожній, зроблений для зручної реєстрації в DI контейнері;
• об’єкт TelemetryConfiguration присутній у DI контейнері, тому дістати його можна звідти.

Резюме

Телеметрія — тема дуже цікава та досить об’ємна. Спочатку я хотів написати про те, як телеметрія працює і як це влаштовано зсередини .NET. Ідея ця у мене з’явилася кілька місяців тому.

Але коли я почав думати про те, що написати, то в голові була каша, бо написати можна дуже багато. Тільки на опис трасувань у мене пішло більше як місяць часу, тому що інформації багато, її складно структурувати і водночас зробити такою, щоб читач не заснув за читанням 377 сторінок.

Тож початковий план на статтю провалився, але вийшов ось цей матеріал. Якщо тема цікава й приверне увагу, може, буде якесь продовження.