AUTO_CLOSE и наказание калёным железом
Если бы SQL Server существовал во времена Инквизиции, то за включение некоторых опций на продакшен серверах нужно было бы наказывать калёным железом. Но если отбросить лирику, то далее на рассмотрим почему не нужно включать AUTO_CLOSE и к чему может привести использование этой опции.
Собственно, как и любая интересная истории из жизни, все начиналось с рутиной задачи.
На днях пришлось заглянуть в Error Log на тестовом сервере. На второй минуте ожидания, SSMS изрядно поплохело от обилия сообщений, которые хранил журнал, и я решил посмотреть сколько же весят логи с помощью xp_enumerrorlogs:
DECLARE @t TABLE (lod_id INT PRIMARY KEY, last_log SMALLDATETIME, size INT)
INSERT INTO @t
EXEC sys.xp_enumerrorlogs
SELECT lod_id, last_log, size_mb = size / 1048576.
FROM @t
lod_id last_log size_mb
-------- --------------------- ---------------
0 2016-01-05 08:46:00 567.05288505
1 2015-12-31 12:53:00 1370.39249420
2 2015-12-18 11:32:00 768.46394729
3 2015-12-02 13:54:00 220.20050621
4 2015-12-02 13:16:00 24.04152870
5 2015-11-16 13:37:00 80.07946205
6 2015-10-22 12:13:00 109.33527946
Как правило, на тестовых серверах я стараюсь не бороться с размером журнала, поскольку при каждом старте SQL Server-а происходит циклическая смена файлов журнала: текущий журнал errorlog переименовывается в errorlog.1, создается пустой файл errorlog и удаляется самый старый журнал errorlog.6.
В случае, когда возникает необходимо очистить журналы, то на помощь может прийти sp_cycle_errorlog. Но перед тем как очистить журналы, все же захотелось понять, что в них такого интересного записано.
Выполнил чтение из текущего журнала с помощью хранимой процедуры xp_readerrorlog:
EXEC sys.xp_readerrorlog
И тут моему периферийному зрению попались на глаза многочисленные сообщения:
Starting up database '...'.
С одной стороны, в этом нет ничего плохого. При каждом старте SQL Server открывает файлы данных и проверяет загрузочную страницу:
Starting up database '...'.
CHECKDB for database '...' finished without errors on ... (local time).
Но после того как я отфильтровал по искомому сообщению, результаты выборки заставили задуматься:
DECLARE @t TABLE (log_date SMALLDATETIME, spid VARCHAR(50), msg NVARCHAR(4000))
INSERT INTO @t
EXEC sys.xp_readerrorlog 0, 1, N'Starting up database'
SELECT msg, COUNT_BIG(1)
FROM @t
GROUP BY msg
HAVING COUNT_BIG(1) > 1
ORDER BY 2 DESC
------------------------------------------------------ --------------------
Starting up database 'AUTOTEST_DESCRIBER'. 127723
Starting up database 'MANUAL_DESCRIBER'. 12913
Starting up database 'AdventureWorks2012'. 12901
Большое количество такого рода сообщений может возникать из-за включения опции AUTO_CLOSE.
Согласно документации, при включении опции AUTO_CLOSE база данных будет автоматически закрываться и высвобождать все занимаемые ею ресурсы, когда перестает существовать последнее пользовательское соединение использующее эту БД. При повторном обращении база будет автоматически переоткрываться… и так до бесконечности.
Когда-то давно читал, что на физическом уровне операция AUTO_CLOSE для старых версий SQL Server являлась полностью синхронным процессом, который мог вызывать большие задержки при постоянных переоткрытиях файлов БД. Начиная с SQL Server 2005, AUTO_CLOSE стал асинхронным и часть проблем ушла. А что осталось? Достаточно всего, чтобы не пользоваться этой опцией…
Для оптимизации производительности SQL Server выполняет изменения страниц в буферном кеше и не записывает эти страницы на диск после каждой модификации. Вместо этого SQL Server периодически создает контрольную точку, по которой записывает текущие страницы, измененные в памяти, вместе со сведениями журнала транзакций из памяти на диск. При закрытии базы данных автоматически выполняется CHECKPOINT. Соответственно при постоянных закрытиях БД может сильно возрастать дисковая нагрузка.
Также при каждом закрытии базы данных очищается её процедурный кеш. Соответственно, когда база повторно откроется придётся генерировать планы выполнения по новой. Но что еще печальнее… при закрытии очищается также и буферный кеш, что увеличивает дисковую нагрузку при выполнении запросов.
Microsoft со мной солидарна и также не рекомендует включать AUTO_CLOSE:
When AUTO_CLOSE is set ON, this option can cause performance degradation on frequently accessed databases because of the increased overhead of opening and closing the database after each connection. AUTO_CLOSE also flushes the procedure cache after each connection.
Однако есть пара нюансов. Если Вы используете SQL Server 2000 или любую Express редакцию, то при создании новой базы данных, опция AUTO_CLOSE будет неявно включаться:
USE [master]
GO
IF DB_ID('test') IS NOT NULL
DROP DATABASE [test]
GO
CREATE DATABASE [test]
GO
SELECT is_auto_close_on
FROM sys.databases
WHERE database_id = DB_ID('test')
is_auto_close_on
----------------
1
Браво Microsoft! Стоячие овации…
Хотя если посмотреть с другой стороны, для SQL Server Express такое поведение вполне объяснимо, поскольку в рамках этой редакции существует ограничение на размер используемой ОЗУ — не более 1 Гб.
Но на будущее, если вдруг потребуется разворачивать базу данных с помощью скрипта, лучше перестраховаться и явно отключать AUTO_CLOSE:
ALTER DATABASE [test] SET AUTO_CLOSE OFF
В процессе работы я заметил еще один интересный момент — при обращении к некоторым функциям или системным представлениям, все базы данных с включенной опцией AUTO_CLOSE будут открываться:
USE [master]
GO
IF DB_ID('p1') IS NOT NULL
DROP DATABASE [p1]
GO
CREATE DATABASE [p1]
GO
ALTER DATABASE [p1] SET AUTO_CLOSE ON
GO
IF DB_ID('p2') IS NOT NULL
DROP DATABASE [p2]
GO
CREATE DATABASE [p2]
GO
ALTER DATABASE [p2] SET AUTO_CLOSE ON
GO
EXEC sys.xp_readerrorlog 0, 1, N'Starting up database ''p'
GO
LogDate ProcessInfo Text
----------------------- ------------ ----------------------------------
2016-01-25 17:36:40.310 spid53 Starting up database 'p1'.
2016-01-25 17:36:41.980 spid53 Starting up database 'p2'.
Мы обращаемся к p1:
WAITFOR DELAY '00:03'
GO
SELECT DB_ID('p1')
GO
EXEC sys.xp_readerrorlog 0, 1, N'Starting up database ''p'
Но p2 тоже просыпается «за компанию»:
LogDate ProcessInfo Text
----------------------- ------------ ----------------------------------
2016-01-25 17:36:40.310 spid53 Starting up database 'p1'.
2016-01-25 17:36:41.980 spid53 Starting up database 'p2'.
2016-01-25 17:39:17.440 spid52 Starting up database 'p1'.
2016-01-25 17:39:17.550 spid52 Starting up database 'p2'.
И вот наконец мы докопались до истины. На сервере различные пользователи активно обращались к метаданным… это заставляло просыпаться базы данных с включенным AUTO_CLOSE, что в свою очередь неявно вызывало рост журнала.
Превентивные меры, кстати, вышли очень простыми:
DECLARE @SQL NVARCHAR(MAX)
SELECT @SQL = (
SELECT '
ALTER DATABASE ' + QUOTENAME(name) + ' SET AUTO_CLOSE OFF WITH NO_WAIT;'
FROM sys.databases
WHERE is_auto_close_on = 1
FOR XML PATH(''), TYPE).value('.', 'NVARCHAR(MAX)')
EXEC sys.sp_executesql @SQL
Все тестировалось на Microsoft SQL Server 2012 (SP3) (KB3072779) — 11.0.6020.0 (X64).
Собственно, на этом все. Всем спасибо за внимание.
Теперь позвольте опять пару слов сказать по другой теме…
В конце этого месяца, состоится небольшая встреча юзер-группы по SQL Server. В рамках нее планируется 2 доклада. Один будет от меня в рамках которого я затрону вопросы производительности при работе с XML и XQuery. Второй доклад будет про системы контроля версий для баз данных.
Место проведения: Украина, г. Харьков, ул. Маломясницкая, 9/11 (ст. метро пр. Гагарина) на базе академии «ШАГ»
Время начала: 29 января 2016 в 18:00
Участие полностью бесплатное.
Дополнительная информация тут.
