MS SQL Server дело тонкое...: Расчёт задержки в сети между репликами группы доступности Always On

Автор: Paul Ou Yang, A Better Fire Alarm Is Still a Fire

У нас было бизнес-требование добавить облачную асинхронную реплику к локальной группе доступности SQL Server Always On. После добавления высоконагруженной базы данных в группу доступности мы заметили, что очередь отправки журнала начала быстро расти.

Нашим первоначальным подозрением было, что задержка в сети между локальной первичной репликой и облачной репликой вносит вклад в проблему. Однако прежде чем запрашивать модернизацию сети, нам нужен был способ доказать, что производительность сети действительно влияет на перемещение данных.

Один из полезных подходов — использовать трассировку Extended Events для перемещения данных Always On, описанную в статье Microsoft: Troubleshooting data movement latency between synchronous-commit AlwaysOn Availability Groups

Хотя пример Microsoft фокусируется на реплике с синхронной фиксацией, те же события перемещения данных можно использовать для исследования асинхронной реплики, но с некоторыми важными отличиями.

Первый симптом: растущая очередь отправки

Первым признаком было то, что очередь отправки журнала была значительно больше, чем очередь повтора (redo).

Например:

SELECT
    ar.replica_server_name AS ReplicaName,
    DB_NAME(drs.database_id) AS DatabaseName,
    drs.log_send_queue_size AS LogSendQueueKB,
    drs.redo_queue_size AS RedoQueueKB
FROM sys.dm_hadr_database_replica_states drs
JOIN sys.availability_replicas ar
    ON drs.replica_id = ar.replica_id
WHERE DB_NAME(drs.database_id) = 'DB1';

Результат выглядел так:

ReplicaName	DatabaseName	LogSendQueueKB	RedoQueueKB
SQL1	DB1	79,604,352	88

Важное наблюдение — разница между двумя очередями. Очередь отправки составляла примерно 76 ГБ, в то время как очередь повтора — только 88 КБ.

Это указывало на то, что вторичная реплика не испытывала трудностей с повторным применением уже полученного журнала. Вместо этого значительный объём журнала накапливался до того, как он мог быть доставлен на вторичную реплику.

Это сделало пропускную способность или задержку сети сильным кандидатом для дальнейшего расследования.

Захват трассировки перемещения данных

Следующим шагом был захват трассировки перемещения данных Always On как на первичной, так и на вторичной репликах.

Важно запускать трассировку примерно в течение одного и того же периода времени на обоих серверах, чтобы события можно было сопоставить.

В нашем случае мы захватывали трассировку в течение 2 минут 30 секунд.

IF EXISTS
(
    SELECT *
    FROM sys.server_event_sessions
    WHERE name = 'AlwaysOn_Data_Movement_Tracing'
)
BEGIN
    DROP EVENT SESSION [AlwaysOn_Data_Movement_Tracing]
    ON SERVER;
END
GO

CREATE EVENT SESSION [AlwaysOn_Data_Movement_Tracing] ON SERVER
ADD EVENT sqlserver.hadr_apply_log_block,
ADD EVENT sqlserver.hadr_capture_filestream_wait,
ADD EVENT sqlserver.hadr_capture_log_block,
ADD EVENT sqlserver.hadr_capture_vlfheader,
ADD EVENT sqlserver.hadr_db_commit_mgr_harden,
ADD EVENT sqlserver.hadr_log_block_compression,
ADD EVENT sqlserver.hadr_log_block_decompression,
ADD EVENT sqlserver.hadr_log_block_group_commit,
ADD EVENT sqlserver.hadr_log_block_send_complete,
ADD EVENT sqlserver.hadr_lsn_send_complete,
ADD EVENT sqlserver.hadr_receive_harden_lsn_message,
ADD EVENT sqlserver.hadr_send_harden_lsn_message,
ADD EVENT sqlserver.hadr_database_flow_control_action,
ADD EVENT sqlserver.hadr_transport_flow_control_action,
ADD EVENT ucs.ucs_connection_flow_control,
ADD EVENT sqlserver.hadr_transport_receive_log_block_message,
ADD EVENT sqlserver.log_block_pushed_to_logpool,
ADD EVENT sqlserver.log_flush_complete,
ADD EVENT sqlserver.recovery_unit_harden_log_timestamps
ADD TARGET package0.event_file
(
    SET filename = N'E:\AlwaysOn_Data_Movement_Tracing.xel',
        max_file_size = (500),
        max_rollover_files = (4)
)
WITH
(
    MAX_MEMORY = 4096 KB,
    EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS,
    MAX_DISPATCH_LATENCY = 30 SECONDS,
    MAX_EVENT_SIZE = 0 KB,
    MEMORY_PARTITION_MODE = NONE,
    TRACK_CAUSALITY = OFF,
    STARTUP_STATE = ON
);
GO

ALTER EVENT SESSION [AlwaysOn_Data_Movement_Tracing]
ON SERVER STATE = START;

WAITFOR DELAY '00:02:30';

ALTER EVENT SESSION [AlwaysOn_Data_Movement_Tracing]
ON SERVER STATE = STOP;
GO

Важно: Extended Events могут генерировать значительный объём данных на загруженном SQL Server. Держите окно захвата как можно короче и следите за размером файлов .xel.

Поиск блока журнала для сопоставления

После сбора трассировки нам нужно идентифицировать базу данных в трассировке.

На вторичной реплике выполните:

SELECT group_database_id
FROM sys.availability_databases_cluster
WHERE database_name = 'DB1';

В нашем примере результат был:

group_database_id
------------------------------------
3F5E2823-002E-46FD-A971-869ED3892B27

Мы можем использовать это значение для поиска событий, связанных с DB1, в выводе Extended Events.

Например, трассировка вторичной реплики содержала такие события:

name	timestamp	database_replica_id	mode	log_block_id
hadr_transport_receive_log_block_message	2026-08-04 09:20:17.2059851	3F5E2823-002E-46FD-A971-869ED3892B27	2	28346698302255272
hadr_apply_log_block	2026-08-04 09:20:17.2060235	3F5E2823-002E-46FD-A971-869ED3892B27	2	28346698302255032
hadr_transport_receive_log_block_message	2026-08-04 09:20:17.2060465	3F5E2823-002E-46FD-A971-869ED3892B27	1	28346698302255392
hadr_apply_log_block	2026-08-04 09:20:17.2060554	3F5E2823-002E-46FD-A971-869ED3892B27	2	28346698302255152
hadr_transport_receive_log_block_message	2026-08-04 09:20:17.2060730	3F5E2823-002E-46FD-A971-869ED3892B27	1	28346698302255512
hadr_transport_receive_log_block_message	2026-08-04 09:20:17.2060836	3F5E2823-002E-46FD-A971-869ED3892B27	2	28346698302255392
hadr_apply_log_block	2026-08-04 09:20:17.2060849	3F5E2823-002E-46FD-A971-869ED3892B27	2	28346698302255272

Выберите log_block_id, желательно ближе к концу трассировки. Это увеличивает шанс, что тот же блок журнала был захвачен как в первичной, так и во вторичной трассировке.

Для этого примера мы выбрали:

28346698302255392

Поиск блока журнала на вторичной реплике

Поиск этого ID блока журнала на вторичной реплике дал следующие результаты:

name	timestamp	database_replica_id	mode	log_block_id
hadr_transport_receive_log_block_message	2026-08-04 09:20:17.2060465	3F5E2823-002E-46FD-A971-869ED3892B27	1	28346698302255392
hadr_transport_receive_log_block_message	2026-08-04 09:20:17.2060836	3F5E2823-002E-46FD-A971-869ED3892B27	2	28346698302255392
hadr_log_block_decompression	2026-08-04 09:20:17.2061251	NULL	NULL	28346698302255392
hadr_log_block_decompression	2026-08-04 09:20:17.2061274	NULL	NULL	28346698302255392
hadr_apply_log_block	2026-08-04 09:20:17.2061456	3F5E2823-002E-46FD-A971-869ED3892B27	2	28346698302255392
log_block_pushed_to_logpool	2026-08-04 09:20:17.2063843	NULL	NULL	28346698302255392
log_flush_complete	2026-08-04 09:20:17.2068296	NULL	NULL	28346698302255392

Поиск того же блока журнала на первичной реплике

Затем выполните поиск в трассировке первичной реплики по тому же log_block_id:

28346698302255392

Соответствующие события были:

name	timestamp	database_replica_id	availability_replica_id	log_block_id
hadr_capture_log_block	2026-08-04 09:19:07.1730670	3F5E2823-002E-46FD-A971-869ED3892B27	D91DF70A-8226-4022-93F6-12F4D5B77699	28346698302255392
hadr_capture_filestream_wait	2026-08-04 09:19:07.1730674	3F5E2823-002E-46FD-A971-869ED3892B27	D91DF70A-8226-4022-93F6-12F4D5B77699	28346698302255392
hadr_capture_log_block	2026-08-04 09:19:07.1730690	3F5E2823-002E-46FD-A971-869ED3892B27	D91DF70A-8226-4022-93F6-12F4D5B77699	28346698302255392
hadr_capture_log_block	2026-08-04 09:20:16.6305401	3F5E2823-002E-46FD-A971-869ED3892B27	D91DF70A-8226-4022-93F6-12F4D5B77699	28346698302255392
hadr_capture_log_block	2026-08-04 09:20:16.6305465	3F5E2823-002E-46FD-A971-869ED3892B27	D91DF70A-8226-4022-93F6-12F4D5B77699	28346698302255392
hadr_log_block_compression	2026-08-04 09:20:16.6307262	NULL	D91DF70A-8226-4022-93F6-12F4D5B77699	28346698302255392
hadr_log_block_send_complete	2026-08-04 09:20:16.9981083	NULL	NULL	28346698302255392

Строка, выделенная серым цветом, — это ключевое событие, которое нам нужно от первичной реплики: hadr_log_block_send_complete.

Асинхронные реплики имеют важные отличия

Одна важная деталь заключается в том, что события, захватываемые для асинхронной реплики, немного отличаются от тех, что показаны в примере Microsoft для синхронной реплики.

При асинхронной репликации первичная реплика сжимает блоки журнала перед отправкой, а вторичная — распаковывает их после получения.

В результате мы видим:

hadr_log_block_compression на первичной реплике
hadr_log_block_decompression на вторичной реплике

Также есть важное различие в том, как первичная реплика ожидает вторичную.

С асинхронной репликой первичная реплика не ждёт, пока вторичная реплика закрепит (harden) блок журнала, прежде чем продолжить. Поэтому мы не должны ожидать того же полного цикла hadr_receive_harden_lsn_message, который используется в примере с синхронной фиксацией.

Это делает часть перемещения данных от первичной к вторичной особенно полезной при исследовании задержки в сети для асинхронной реплики.

События, необходимые для расчёта задержки в сети

Два события, которые нас интересуют:

Первичная реплика

hadr_log_block_send_complete

2026-08-04 09:20:16.9981083

Вторичная реплика

hadr_transport_receive_log_block_message

2026-08-04 09:20:17.2060465

Оба события соответствуют одному и тому же блоку журнала:

28346698302255392

Расчёт задержки в сети

Мы можем вычислить разницу между этими временными метками с помощью DATEDIFF:

SELECT DATEDIFF(
    millisecond,
    '2026-08-04 09:20:16.9981083',
    '2026-08-04 09:20:17.2060465'
);

Результат составляет примерно: 208

Другими словами, время, прошедшее между тем, как первичная реплика сообщила об отправке блока журнала, и тем, как вторичная реплика сообщила о его получении, составило примерно 208 миллисекунд.

Заключение

Это дало нам гораздо более весомую информацию, чем просто утверждение «сеть, кажется, медленная».

Мы смогли сопоставить один и тот же log_block_id на первичной и вторичной репликах и измерить время между событием hadr_log_block_send_complete на первичной реплике и событием hadr_transport_receive_log_block_message на вторичной реплике.

В этом примере это измерение составило примерно 208 миллисекунд.

В сочетании с быстро растущей очередью отправки и относительно небольшой очередью повтора, трассировка предоставила доказательства того, что производительность сети была значительным фактором в способности асинхронной реплики успевать за первичной.

Эти данные дали нам доказательства, необходимые для обоснования модернизации сети, вместо того чтобы рассматривать проблему как общую проблему производительности SQL Server.

MS SQL Server дело тонкое...

18.8.26

Расчёт задержки в сети между репликами группы доступности Always On

Первый симптом: растущая очередь отправки

Захват трассировки перемещения данных

Поиск блока журнала для сопоставления

Поиск блока журнала на вторичной реплике

Поиск того же блока журнала на первичной реплике

Асинхронные реплики имеют важные отличия

События, необходимые для расчёта задержки в сети

Первичная реплика

Вторичная реплика

Расчёт задержки в сети

Заключение

Комментариев нет:

Отправить комментарий

Архив блога

Ярлыки

www.sql-ex.ru