«Круговорот» журнала транзакций.
Продолжим работу с нашей тестовой базой и на ее примере постараемся понять крайне важную концепцию «цикличности» логического лог файла. Физический лог файл, понятное дело, есть статичный файл на HDD (или набор таких файлов, что ровным счетом ничего не меняет). OS Windows совершенно не колеблясь скажет нам где именно этот файл начинается и где он заканчивается. Если исходить из предположения, что размер физического лога измениться не может (наша тестовая база, кстати, реализована именно по такому принципу), то, очевидно, две указанные границы зафиксированы «навсегда» (дефрагментацию диска не учитываем). Совсем иное дело когда речь заходит о логическом файле. Вот тут уже никаких «фиксированных границ» нет и в помине, все настолько зыбко, «эластично», что... Впрочем, давайте по-порядку.
Если база TstLog у вас в данный момент существует — «сбрасывайте» ее, дабы начать с «чистого листа»:
1 2 3 | USE master go DROP DATABASE TstLog |
Для начала этого большого (и довольно сложного, не буду вас обманывать) раздела нашей «рабочей лошадкой» станет такой скрипт (только снова убедитесь, что на вашем компьютере все в порядке с путями к файлам базы):
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 | USE master go CREATE DATABASE TstLog ON PRIMARY ( NAME = 'TstLog_Data', FILENAME = 'c:\sqlCMD.ru\TstLog_Data.mdf', SIZE = 5 MB, MAXSIZE = 5 MB ) LOG ON ( NAME = 'TstLog_Log', FILENAME = 'c:\sqlCMD.ru\TstLog_Log.ldf', SIZE = 1 MB, MAXSIZE = 1 MB ) GO ALTER DATABASE TstLog SET RECOVERY SIMPLE GO USE TstLog GO CREATE TABLE T1 (C1 INT IDENTITY, C2 INT NOT NULL, C3 VARCHAR(20) NOT NULL) GO declare @i int = 0 BEGIN TRAN WHILE @i < 500 --loop counter BEGIN insert into T1 VALUES (17, REPLICATE('S', 20)) set @i += 1 END COMMIT TRAN go DBCC LOGINFO --clean up USE master go DROP DATABASE TstLog |
Ничего особо экстраординарного не происходит: открыли транзакцию, произвели 500 вставок, закрыли транзакцию, посмотрели отчет по использованию VLF-ов. Отчет сообщает нам:
2 253952 8192 70 2 64 0
2 253952 262144 0 0 0 0
2 253952 516096 0 0 0 0
2 278528 770048 0 0 0 0
Поскольку мы дальновидно изучили команду DBCC LOGINFO заранее, то отчет более чем ожидаем: записями заполнен лишь первый из VLF-ов, причем, очевидно, заполнен не на 100% (точные цифры для нас сейчас не существенны). Потому и визуальное представление текущего положения дел в логе практически не будет отличаться от виденного нами ранее:
Разница с предыдущей иллюстрацией лишь в том, что мы не будем более выделять каждую запись в логе персональным прямоугольника, а просто, по мере роста их числа будем «заливать» пустые VLF-ы (что символизируют зеленые квадраты) красным фоном. Как только очередной VLF заполнится «от края до края» он весь станет красным.
Таким образом, согласно нашему графическому представлению, на текущий момент у нас лишь первый VLF заполнен записями на некоторое количество процентов, ровно как и сообщил нам последний отчет. Хорошо, а если loop counter последнего скрипта поднять до 2-х тысяч и перезапустить тот же скрипт? Тогда отчет станет таким:
2 253952 8192 70 2 64 0
2 253952 262144 71 2 64 0
2 253952 516096 0 0 0 0
2 278528 770048 0 0 0 0
А в графическом виде — таким:
Тоже пока ничего особо интересного, ну заполнены записями 2 VLF-а, предположительно почти до конца. Очевидно, что еще пару тысяч строк влезет запросто — еще «чуть-чуть» места под записи есть в VLF2, плюс пара вообще свободных VLF-ов, плюс тот факт, что последний (и свободный в настоящее время) VLF за номером 4 несколько «крупнее» своих собратьев (грубо, 278кБ против 253кБ у трех остальных). Ну то есть счетчик на 4000 можно ставить «не глядя», а, почти наверняка, и 4500 не станут непосильной ношей для нашего лога — верно? Конечно! Вот возьмем мы (исключительно с целью плавного приближения к максимальной отметке записей в логе) цифру 2300 (что, конечно же, смешно, как мы только что выяснили) и запустим скрипт с нею по новой. Уже заранее понятно что мы увидим: ну будет этими несчастными дополнительными тремястами записями «захвачен» левый край третьего VLF-а, а то может и второй только-только до конца заполнится — чего тут смотреть-то? Но все же — запустим? Ладно, уговорили, запускаем, и...
The transaction log for database 'TstLog' is full. To find out why space in the log cannot be reused,
see the log_reuse_wait_desc column in sys.databases
Это вообще — что такое??! 
У нас после 2-х тысяч записей лог и на половину не заполнен, как могут еще 300 аналогичных записей сделать его full? Ну явно ж сервер «дуркует», надо на форум сообщить...
И сообщают, а вы как думали? Ну действительно — мистика какая-то, и «фигня на ровном месте». И что бы с эти самым «местом» разобраться нам придется снова прервать плавное течение рассказа и сместиться немного в сторону. Тема лога вообще изобилует отходами «вбок», «по диагонали», а так же перемещениями в параллельных плоскостях повествования. Привыкайте — таков уж наш главный герой: на лог влияет буквально все, но и обратное тоже верно — лог влияет практически на все прочие компоненты SQL сервера. Чему ж тут удивляться? Мы обречены время от времени отвлекаться на побочные механизмы и изучать их, а так же их влияние на журнал транзакций.
Как ROLLBACK отражается в записях лога.
Мы уже рассмотрели вопрос «CHECKPOINT и откат транзакций». Из наших наблюдений мы сделали вывод, что ROLLBACK — команда весьма «себе на уме»: действует, в общем-то, логично, но вот мало кто интуитивно ожидает от нее такой логики и, особенно, такой прыти в «отжирании» ресурсов сервера. Ну да, мы уточнили — ресурсы «жжет» не сама команда ROLLBACK, а последствия ее применения. Но поскольку ROLLBACK и ее последствия есть (если обойтись без философствования) единое и неделимое целое, то «виновата» все-таки она, эта команда. Помимо этого автор обещал что все сказанное в том разделе лишь часть правды, а вся она откроется позже. А именно — прямо сейчас.
Давайте сразу вот как:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 | USE master go CREATE DATABASE TstLog ON PRIMARY ( NAME = 'TstLog_Data', FILENAME = 'c:\sqlCMD.ru\TstLog_Data.mdf', SIZE = 5 MB, MAXSIZE = 5 MB ) LOG ON ( NAME = 'TstLog_Log', FILENAME = 'c:\sqlCMD.ru\TstLog_Log.ldf', SIZE = 1 MB, MAXSIZE = 1 MB ) GO ALTER DATABASE TstLog SET RECOVERY SIMPLE GO USE TstLog GO CREATE TABLE T1 (C1 INT IDENTITY, C2 INT NOT NULL, C3 VARCHAR(20) NOT NULL) INSERT INTO T1 VALUES (10, 'A') INSERT INTO T1 VALUES (20, 'B') GO CHECKPOINT GO BEGIN TRANSACTION INSERT INTO T1 VALUES (50, 'V') INSERT INTO T1 VALUES (70, 'Z') UPDATE T1 SET C3='Q' WHERE C2=70 COMMIT TRANSACTION DBCC LOG(TstLog, 1) --clean up USE master go DROP DATABASE TstLog |
Если сосредоточиться на нижней части отчета (где и происходит все самое интересное), то мы увидим, что главные операции нашей транзакции состоящей из трех инструкций выглядят таким образом:
00000046:0000008f:0002 LOP_BEGIN_XACT 0000:00000571
00000046:0000008f:0003 LOP_INSERT_ROWS 0000:00000571
...
00000046:0000008f:0005 LOP_INSERT_ROWS 0000:00000571
00000046:0000008f:0006 LOP_MODIFY_ROW 0000:00000571
00000046:0000008f:0007 LOP_COMMIT_XACT 0000:00000571
Переводя «на русский»: открыли → вставили пару строк → модифицировали одну → зафиксировали. Все четко, компактно, по делу.
Исправим в последнем скрипте одно слово: COMMIT на ROLLBACK. И вновь запустим его. И снова проанализируем нижние строчки отчета:
00000046:0000008f:0002 LOP_BEGIN_XACT 0000:00000571
00000046:0000008f:0003 LOP_INSERT_ROWS 0000:00000571
...
00000046:0000008f:0005 LOP_INSERT_ROWS 0000:00000571
00000046:0000008f:0006 LOP_MODIFY_ROW 0000:00000571
00000046:0000008f:0007 LOP_MODIFY_ROW 0000:00000571
00000046:0000008f:0008 LOP_DELETE_ROWS 0000:00000571
00000046:0000008f:0009 LOP_DELETE_ROWS 0000:00000571
00000046:0000008f:000a LOP_ABORT_XACT 0000:00000571
И? Как вам это (не)нравится? Вместо трех строк (старт и финиш транзакции отбрасываем — это само-собой) — шесть! И причем, можете не сомневаться, каждая «дополнительная» строка «весит» как и «основная», ибо точно так же как последняя содержит полную «расчлененку» каждой инструкции: что меняется, на что меняется, номер предыдущей операции в «цепочке» и т.д. Да и более того, вес каждой «дополнительной» записи будет и слегка побольше записи «основной», поскольку у «дополнительных» в колонке Description значится очень говорящее слово COMPENSATION, а у основных записей данная колонка чиста. Почему это слово «говорящее» и о чем, собственно, оно «говорит», спрашиваете вы?
Оно говорит нам о том, что вообще, в «академическом» смысле этого вопроса, решить задачу отмены какой-то операции можно двумя путями:
- удалить саму операцию. То есть, для нашего примера, сделать вид что пара строк никогда не вставлялась, и одна из них никогда не менялась. При таком подходе из лога нужно было бы просто «вычистить» записи о трех операциях;
- сделать операцию встречную отменяемой. В нашем примере: изменить значение колонки C3 на оригинальное в одной строке, а потом удалить ее и еще одну строку. При таком подходе из лога ничего не «вычищается», а, ровно наоборот, добавляются новые записи. И, разумеется, выполняются действия этими записями обозначенные: строки модифицируются, удаляются и т.д.
Автору неизвестна ни одна СУБД с гарантией транзакционной целостности, авторы которой пошли бы по первому пути. Все пошли по второму. И уж совершенно определенно, что касается SQL Server, то тут вообще никаких сомнений быть не может — при откате транзакции число операций увеличивается, а значит работает вторая модель, зовущаяся компенсационной моделью отмены операций. Понимаете теперь, почему автор назвал слово COMPENSATION «говорящим»? Правильно, потому что оно подчеркивает назначение той записи лога что им помечена. Такие записи являются компенсационными и известны в англоязычной литературе под термином compensation log records.
Так что же, наши эксперименты, похоже, подтверждают статус «ресурсопрожорлива» для инструкции ROLLBACK? Я бы сказал не только подтверждают, а еще и умножают его на два! В общем случае, выполняя ROLLBACK готовьтесь получить:
- дополнительную нагрузку на дисковую подсистему ввода-вывода;
- «захвату» свободного места в RAM
- «захвату» свободного места на HDD
Разумеется, возможно что все эти три пункта будут столь незначительны, что их никто и не заметит. Но возможно и обратное: заметят, да еще как! «Генеральный» вывод однозначен: с точки зрения экономии ресурсов ROLLBACK не выгоден. Точка. Что ни разу не означает «забудьте об этой команде». Забыть о ней невозможно, это один из краеугольных камней всей транзакционной системы. Пользуйтесь ей на здоровье, но делайте это осмотрительно. В том числе и в том смысле какой вкладывает в это слово данный подраздел статьи.
Наконец, давайте выясним вопрос практически примыкающий к вопросу потребления ресурсов командами COMMIT и ROLLBACK. Что у нас со временем их исполнения? Можно ли утверждать, что транзакция завершающаяся фиксацией (commit) будет выполняться быстрее, нежели та же самая транзакция завершающаяся откатом (rollback)? С учетом предыдущего абзаца очень хочется сразу дать положительный ответ и закрыть дискуссию. Но — не будем торопиться.
Вот как подошел к вопросу автор. Очевидно, что программная структура время которой мы пытаемся измерить будет иметь такой общий вид:
- открытие транзакции
- операция/операции модификации («ядро» транзакции)
- фиксация или откат транзакции
Пунктом 1-м, очевидно, можно пренебречь. Во-первых открытие транзакции инструкция более чем «легковесная», во-вторых ее время эквивалентно для обоих сравниваемых вариантов. Пункт 2 (собственно — содержимое транзакции) тоже будет, очевидно, выполнятся идентично и равное число миллисекунд вне зависимости что там последует в пункте 3. Однако интересно сопоставить время исполнения этого пункта и следующего. Просто что бы оценить отношение одного к другому. В опытах автора пункт 2 сводился к единственному UPDATE-у, но весьма сложному: отбор строк подлежащих модификации выполнялся через JOIN трех тестовых таблиц (а изменения вносились в одну из них). Наконец, пункт 3 состоял из единственной инструкции COMMIT TRANSACTION в одном случае и единственного же ROLLBACK TRANSACTION в другом. Время выполнения измерялось для пунктов 2 и 3 отдельно. Измерения повторялись не только для разных инструкций 3-го пункта, но и для разного начального числа строк в трех тестовых таблицах. Точность измерения — 1 миллисекунда. Опуская сам тестовый скрипт (он получился достаточно объемным что бы тратить на него место в статье), автор сразу же приводит итоговую таблицу своих экспериментов:
| Число обрабатываемых строк | UPDATE, ms | COMMIT, ms | ROLLBACK, ms |
| 10 | 10220 | 1 | 1 |
| 100 | 11416 | 1 | 56 |
| 1000 | 16636 | 15 | 754 |
| 10000 | 40448 | 19 | 5001 |
При всей приблизительности подсчетов, и даже учитывая бесконечное многообразие комбинаций T-SQL команд могущих составить 2-й пункт в реальном коде, общая тенденция соотношения затрачиваемого времени ясна как день: ROLLBACK является более длительной операцией чем COMMIT. И причем чем «тяжелее» сама транзакция (т.е. ее пункт 2), тем разница становится ощутимее и вполне может достигать порядков(!). Но! Означенную тенденцию более корректно будет записать так: «чистый ROLLBACK требует [значительно] больше времени чем чистый COMMIT». Поправка весьма существенна, т.к. анализируемая нами конструкция без своего 2-го пункта просто никому не нужна, именно тут заключено «ядро» функциональности всей транзакции. Так не будет ли корректным прибавлять к времени COMMIT-а время той операции которую он, собственно «коммитит»? Ведь без нее не будет и COMMIT-а! А вот тогда расклад сил меняется на совсем противоположный, львиная доля времени уходит как-раз таки на пункт 2, а не на его фиксацию/откат. В общем сложение/разложение времен автор оставляет на усмотрение читателя, факты он изложил, а их интерпретация вопрос где-то, в том числе, и философский. Для нашей же беседы главный итог этого «побочного» повествования такой:
Можно сказать и так: COMMIT=простановка в логе метки «с этим закончили». ROLLBACK=внесение в лог компенсационных записей+модификация данных согласно этим записям+простановка в логе метки «а с этим — передумали».