Автор: Paul Randal, Understanding data vs log usage for spills in tempdb
Сегодня утром я заметил обсуждение в списке рассылки SQL MCM (в котором участвуют все оригинальные инструкторы MCM), где пытались понять причину огромного расхождения между использованием файлов данных и файлов журнала tempdb. Я объяснил ответ и подумал, что поделюсь им и с вами.
Ситуация была такова: файлы данных tempdb выросли с 30 ГБ до 120 ГБ, на диске закончилось место, но файл журнала tempdb вообще не вырос из своего начального размера в 1 ГБ. Как такое могло быть?
Одна из вещей, которую следует учитывать в отношении tempdb, заключается в том, что журналирование в tempdb является сверхэффективным. Например, записи журнала для обновлений в tempdb регистрируют только образ данных «до» («before image») вместо того, чтобы регистрировать как образы «до», так и «после». Нет необходимости регистрировать образ «после» — он используется только для фазы REDO при аварийном восстановлении. Поскольку tempdb никогда не восстанавливается после сбоя, фаза REDO никогда не происходит. Однако образ «до» необходим, поскольку транзакции в tempdb могут быть откачены, как и в других базах данных, и поэтому образ «до» обновления должен быть доступен для успешного отката изменений.
Однако, возвращаясь к вопросу, я могу легко объяснить наблюдаемое поведение, рассмотрев, как происходит сброс (spill) сортировки с использованием tempdb.
Я могу смоделировать это с помощью сложного запроса к базе данных SalesDB, которую вы можете загрузить с нашей страницы ресурсов (см. вверху страницы примеры баз данных для загрузки).
Я собираюсь выполнить соединение таблиц Sales и Products, а затем отсортировать результирующий набор с несколькими миллионами строк по имени продукта:
SELECT S.*, P.* from Sales S
JOIN Products P ON P.ProductID = S.ProductID
ORDER BY P.Name;
GO
Я знаю, что в данном случае сортировка будет «вытесняться» из памяти в tempdb. Сначала я выполняю CHECKPOINT для tempdb (чтобы очистить журнал), а затем после выполнения запроса анализирую журнал транзакций tempdb.
Смотрим на операцию в журнале:
SELECT
[Current LSN],
[Operation],
[Context],
[Transaction ID],
[Log Record Length],
[Description]
FROM fn_dblog (null, null);
GO
Current LSN Operation Context Transaction ID Len Description
———————- ————— ——– ————– — ———————————————————-
000000c0:00000077:0001 LOP_BEGIN_XACT LCX_NULL 0000:00005e4d 120 sort_init;<snip>
000000c0:00000077:0002 LOP_BEGIN_XACT LCX_NULL 0000:00005e4e 132 FirstPage Alloc;<snip>
000000c0:00000077:0003 LOP_SET_BITS LCX_GAM 0000:00005e4e 60 Allocated 1 extent(s) starting at page 0001:0000aa48
000000c0:00000077:0004 LOP_MODIFY_ROW LCX_PFS 0000:00005e4e 88 Allocated 0001:0000aa48;Allocated 0001:0000aa49;
000000c0:00000077:0005 LOP_MODIFY_ROW LCX_PFS 0000:00005e4d 80 Allocated 0001:00000123
000000c0:00000077:0006 LOP_FORMAT_PAGE LCX_IAM 0000:00005e4d 84
000000c0:00000077:0007 LOP_SET_BITS LCX_IAM 0000:00005e4e 60
000000c0:00000077:0009 LOP_COMMIT_XACT LCX_NULL 0000:00005e4e 52
000000c0:00000077:000a LOP_BEGIN_XACT LCX_NULL 0000:00005e4f 128 soAllocExtents;<snip>
000000c0:00000077:000b LOP_SET_BITS LCX_GAM 0000:00005e4f 60 Allocated 1 extent(s) starting at page 0001:0000aa50
000000c0:00000077:000c LOP_MODIFY_ROW LCX_PFS 0000:00005e4f 88 Allocated 0001:0000aa50;Allocated 0001:0000aa51;<snip>
000000c0:00000077:000d LOP_SET_BITS LCX_IAM 0000:00005e4f 60
000000c0:00000077:000e LOP_SET_BITS LCX_GAM 0000:00005e4f 60 Allocated 1 extent(s) starting at page 0001:0000aa58
000000c0:00000077:000f LOP_MODIFY_ROW LCX_PFS 0000:00005e4f 88 Allocated 0001:0000aa58;Allocated 0001:0000aa59;<snip>
000000c0:00000077:0010 LOP_SET_BITS LCX_IAM 0000:00005e4f 60
000000c0:00000077:0011 LOP_SET_BITS LCX_GAM 0000:00005e4f 60 Allocated 1 extent(s) starting at page 0001:0000aa60
000000c0:00000077:0012 LOP_MODIFY_ROW LCX_PFS 0000:00005e4f 88 Allocated 0001:0000aa60;Allocated 0001:0000aa61;<snip>
000000c0:00000077:0013 LOP_SET_BITS LCX_IAM 0000:00005e4f 60
000000c0:00000077:0014 LOP_COMMIT_XACT LCX_NULL 0000:00005e4f 52
000000c0:00000077:0015 LOP_BEGIN_XACT LCX_NULL 0000:00005e50 128 soAllocExtents;<snip>
000000c0:00000077:0016 LOP_SET_BITS LCX_GAM 0000:00005e50 60 Allocated 1 extent(s) starting at page 0001:0000aa68
000000c0:00000077:0017 LOP_MODIFY_ROW LCX_PFS 0000:00005e50 88 Allocated 0001:0000aa68;Allocated 0001:0000aa69;<snip>
000000c0:00000077:0018 LOP_SET_BITS LCX_IAM 0000:00005e50 60
000000c0:00000077:0019 LOP_SET_BITS LCX_GAM 0000:00005e50 60 Allocated 1 extent(s) starting at page 0001:0000aa70
000000c0:00000077:001a LOP_MODIFY_ROW LCX_PFS 0000:00005e50 88 Allocated 0001:0000aa70;Allocated 0001:0000aa71;<snip>
000000c0:00000077:001b LOP_SET_BITS LCX_IAM 0000:00005e50 60
000000c0:00000077:001c LOP_SET_BITS LCX_GAM 0000:00005e50 60 Allocated 1 extent(s) starting at page 0001:0000aa78
000000c0:00000077:001d LOP_MODIFY_ROW LCX_PFS 0000:00005e50 88 Allocated 0001:0000aa78;Allocated 0001:0000aa79;<snip>
000000c0:00000077:001e LOP_SET_BITS LCX_IAM 0000:00005e50 60
000000c0:00000077:001f LOP_SET_BITS LCX_GAM 0000:00005e50 60 Allocated 1 extent(s) starting at page 0001:0000aa80
000000c0:00000077:0020 LOP_MODIFY_ROW LCX_PFS 0000:00005e50 88 Allocated 0001:0000aa80;Allocated 0001:0000aa81;<snip>
000000c0:00000077:0021 LOP_SET_BITS LCX_IAM 0000:00005e50 60
000000c0:00000077:0022 LOP_COMMIT_XACT LCX_NULL 0000:00005e50 52
000000c0:00000077:0023 LOP_BEGIN_XACT LCX_NULL 0000:00005e51 128 soAllocExtents;<snip>
<snip>
000000cd:00000088:01d3 LOP_SET_BITS LCX_GAM 0000:000078fc 60 Deallocated 1 extent(s) starting at page 0001:00010e50
000000cd:00000088:01d4 LOP_COMMIT_XACT LCX_NULL 0000:000078fc 52
000000cd:00000088:01d5 LOP_BEGIN_XACT LCX_NULL 0000:000078fd 140 ExtentDeallocForSort;<snip>
000000cd:00000088:01d6 LOP_SET_BITS LCX_IAM 0000:000078fd 60
000000cd:00000088:01d7 LOP_MODIFY_ROW LCX_PFS 0000:000078fd 88 Deallocated 0001:00010e68;Deallocated 0001:00010e69;<snip>
000000cd:00000088:01d8 LOP_SET_BITS LCX_GAM 0000:000078fd 60 Deallocated 1 extent(s) starting at page 0001:00010e68
000000cd:00000088:01d9 LOP_COMMIT_XACT LCX_NULL 0000:000078fd 52
000000cd:00000088:01da LOP_MODIFY_ROW LCX_PFS 0000:00005fac 80 Deallocated 0001:00000109
000000cd:00000088:01db LOP_SET_BITS LCX_SGAM 0000:00005fac 60 ClearBit 0001:00000108
000000cd:00000088:01dc LOP_SET_BITS LCX_GAM 0000:00005fac 60 Deallocated 1 extent(s) starting at page 0001:00000108
000000cd:00000088:01dd LOP_COMMIT_XACT LCX_NULL 0000:00005fac 52 (Я удалил несколько лишних записей журнала, а также по 6 дополнительных операций Allocated и Deallocated для каждой из модификаций строк PFS.)
Одна из вещей, которую я замечаю, заключается в том, что пространство для сброса сортировки выделяется экстентами, и почти вся сортировка — от инициализации, через выделение всех экстентов, до их освобождения — содержится в нескольких очень больших транзакциях. Но транзакции на самом деле не такие уж большие.
Посмотрите на транзакцию soAllocExtents с идентификатором транзакции 00005e50. Она выделяет 4 экстента, т. е. 256 КБ, в одной системной транзакции (4 раза пометить экстент как недоступный в GAM, 4 раза массово установить 8 байтов PFS для 8 страниц в экстенте, 4 раза пометить экстент как выделенный в IAM). Общий размер записей журнала для этой транзакции составляет 1012 байт. (Первая системная транзакция soAllocExtents выделяет только 3 экстента, все остальные выделяют по 4 экстента.)
По окончании сортировки экстенты освобождаются по одному в системных транзакциях, называемых ExtentDeallocForSort. Примером является транзакция с идентификатором 000078fd. Она генерирует записи журнала общим размером 400 байт. Это означает, что для освобождения каждых 256 КБ требуется 4 × 400 = 1600 байт.
Объединяя операции выделения и освобождения, каждые 256 КБ сортировки, которая «вытесняется» в tempdb, генерируют 2612 байт записей журнала.
Теперь вернёмся к исходному поведению, которое я объяснял. Если 90 ГБ были пространством сортировки:
90 ГБ — это 90 × 1024 × 1024 = 94 371 840 КБ, что составляет 94 371 840 / 256 = 368 640 блоков по 256 КБ.
Каждый блок по 256 КБ требует 2612 байт для выделения и освобождения, поэтому наши 90 ГБ потребовали бы 368 640 × 2612 = 962 887 680 байт журнала, что составляет 962 887 680 / 1024 / 1024 = ~918 МБ журнала.
И это объяснило бы наблюдаемое поведение. 90 ГБ пространства tempdb могут быть выделены и использованы для сброса сортировки примерно с 918 МБ журнала транзакций, с учётом погрешности моих приблизительных расчётов.
Tempdb журналирует операции очень эффективно, особенно то, что вытесняется из памяти. Следующим шагом в отладке такой проблемы был бы регулярный захват вывода sys.dm_db_task_space_usage, чтобы выяснить, кто использует всё пространство, и затем углубиться в исследование оттуда.
Комментариев нет:
Отправить комментарий