Я использую процедуру Ola Hallengren DatabaseBackup для создания резервных копий. У меня есть два задания, настроенные таким образом, что резервное копирование может выполняться параллельно, поскольку у меня есть одна большая база данных, резервное копирование которой занимает 45 минут, и множество более мелких, которые в совокупности занимают 23 минуты — примерно вдвое меньше, чем у самой большой базы данных.

За последнюю неделю было два дня, когда крупнейшая база данных дважды подвергалась резервному копированию, что приводило к проблемам с дисковым пространством. Сначала я думал, что каждое из двух заданий выполняет резервное копирование самой большой БД, но на самом деле это было всего лишь одно задание, выполняющее резервное копирование два раза подряд.

Кто-нибудь видел это раньше? Я не вижу ничего похожего на триггер для второго резервного копирования. Я всегда могу выделить больше места на диске для решения проблемы, так что это не критическая ошибка - мне просто интересно, есть ли у кого-нибудь идеи, почему это может происходить.

Кругозор

[Изменить] Вот файл журнала запуска с двумя резервными копиями. Обычные прогоны выглядят так же, но без второй резервной копии.

Job 'DatabaseBackup - USER_DATABASES - FULL' : Step 1, 'DatabaseBackup - USER_DATABASES - FULL' : Began Executing 2022-01-02 01:05:00

Date and time: 2022-01-02 01:05:00 [SQLSTATE 01000]
Server: SRV-SQLP102 [SQLSTATE 01000]
Version: 13.0.5888.11 [SQLSTATE 01000]
Edition: Enterprise Edition: Core-based Licensing (64-bit) [SQLSTATE 01000]
Platform: Windows [SQLSTATE 01000]
Procedure: [DBA].[dbo].[DatabaseBackup] [SQLSTATE 01000]
Parameters: @Databases = 'USER_DATABASES,-APS_PlanvalTst1', @Directory = 'H:\MSSQLBackups', @BackupType = 'FULL', @Verify = 'Y', @CleanupTime = 120, @CleanupMode = 'AFTER_BACKUP', @Compress = 'Y', @CopyOnly = 'N', @ChangeBackupType = 'N', @BackupSoftware = 'LITESPEED', @CheckSum = 'Y', @BlockSize = NULL, @BufferCount = NULL, @MaxTransferSize = NULL, @NumberOfFiles = NULL, @MinBackupSizeForMultipleFiles = NULL, @MaxFileSize = NULL, @CompressionLevel = NULL, @Description = NULL, @Threads = NULL, @Throttle = NULL, @Encrypt = 'Y', @EncryptionAlgorithm = 'AES_256', @ServerCertificate = NULL, @ServerAsymmetricKey = NULL, @EncryptionKey = '<password>', @ReadWriteFileGroups = 'N', @OverrideBackupPreference = 'N', @NoRecovery = 'N', @URL = NULL, @Credential = NULL, @MirrorDirectory = NULL, @MirrorCleanupTime = NULL, @MirrorCleanupMode = 'AFTER_BACKUP', @MirrorURL = NULL, @AvailabilityGroups = NULL, @Updateability = 'ALL', @AdaptiveCompression = NULL, @ModificationLevel = NULL, @LogSizeSinceLastLogBackup = NULL, @TimeSinceLastLogBackup = NULL, @DataDomainBoostHost = NULL, @DataDomainBoostUser = NULL, @DataDomainBoostDevicePath = NULL, @DataDomainBoostLockboxPath = NULL, @DirectoryStructure = '{ServerName}${InstanceName}{DirectorySeparator}{DatabaseName}{DirectorySeparator}{BackupType}_{Partial}_{CopyOnly}', @AvailabilityGroupDirectoryStructure = '{ClusterName}${AvailabilityGroupName}{DirectorySeparator}{DatabaseName}{DirectorySeparator}{BackupType}_{Partial}_{CopyOnly}', @FileName = '{ServerName}${InstanceName}_{DatabaseName}_{BackupType}_{Partial}_{CopyOnly}_{Year}{Month}{Day}_{Hour}{Minute}{Second}_{FileNumber}.{FileExtension}', @AvailabilityGroupFileName = '{ClusterName}${AvailabilityGroupName}_{DatabaseName}_{BackupType}_{Partial}_{CopyOnly}_{Year}{Month}{Day}_{Hour}{Minute}{Second}_{FileNumber}.{FileExtension}', @FileExtensionFull = NULL, @FileExtensionDiff = NULL, @FileExtensionLog = NULL, @Init = 'N', @Format = 'N', @ObjectLevelRecoveryMap = 'Y', @ExcludeLogShippedFromLogBackup = 'Y', @StringDelimite...
Version: 2020-12-31 18:58:56 [SQLSTATE 01000]
Source: https://ola.hallengren.com [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 01:05:01 [SQLSTATE 01000]
Database: [APS_Arieldb] [SQLSTATE 01000]
State: ONLINE [SQLSTATE 01000]
Standby: No [SQLSTATE 01000]
Updateability: READ_WRITE [SQLSTATE 01000]
User access: MULTI_USER [SQLSTATE 01000]
Recovery model: FULL [SQLSTATE 01000]
Encrypted: No [SQLSTATE 01000]
Is accessible: Yes [SQLSTATE 01000]
Log shipping role: PRIMARY [SQLSTATE 01000]
Differential base LSN: 171335000288621800250 [SQLSTATE 01000]
Last log backup LSN: 171335000319597800001 [SQLSTATE 01000]
Allocated extent page count: 111568608 (871629.750000 MB) [SQLSTATE 01000]
Modified extent page count: 115016 (898.562500 MB) [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 01:05:01 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_create_subdir N'H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL' IF @ReturnCode <> 0 RAISERROR('Error creating directory.', 16, 1) [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:00:00 [SQLSTATE 01000]
Date and time: 2022-01-02 01:05:01 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 01:05:01 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_backup_database @database = N'APS_Arieldb', @filename = N'H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL\SRV-SQLP102_APS_Arieldb_FULL_20220102_010501.bak', @with = 'CHECKSUM', @olrmap = 1, @cryptlevel = 8, @encryptionkey = N'<password>' IF @ReturnCode <> 0 RAISERROR('Error performing LiteSpeed backup.', 16, 1) [SQLSTATE 01000]
SQL> Processed 914 pages for database 'APS_Arieldb', file 'Arielv81_log' on file 1. SQL> BACKUP DATABASE successfully processed 111593234 pages in 2898.516 seconds (300.782 MB/sec). BACKUP DATABASE successfully processed 111593234 pages in 2898.516 seconds (300.782 MB/sec).   BACKUP ATTACHED FILES successfully processed 1 file(s)   Backup added as file number: 1  Output File(s):   H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL\SRV-SQLP102_APS_Arieldb_FULL_20220102_010501.bak   Native Size: 871893.78 MB Backup Size: 108595.84 MB Attachments: 20.41 MB  CPU Seconds: 2558.83 Environment: Intel(R) Xeon(R) Gold 6134 CPU @ 3.20GHz CPUs: 16 logical, 32 cores, 32 physical packages. [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:49:59 [SQLSTATE 01000]
Date and time: 2022-01-02 01:55:00 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 01:55:00 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_restore_verifyonly @filename = N'H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL\SRV-SQLP102_APS_Arieldb_FULL_20220102_010501.bak', @with = 'CHECKSUM', @encryptionkey = N'<password>' IF @ReturnCode <> 0 RAISERROR('Error verifying LiteSpeed backup.', 16, 1) [SQLSTATE 01000]
LiteSpeed® for SQL Server® Version 8.9.5.213 (64bit) Copyright 2020 Quest Software Inc. ALL RIGHTS RESERVED.    CPU Seconds: 1246.91 Environment: Intel(R) Xeon(R) Gold 6134 CPU @ 3.20GHz CPUs: 16 logical, 32 cores, 32 physical packages. [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:07:13 [SQLSTATE 01000]
Date and time: 2022-01-02 02:02:13 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 02:02:13 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_slssqlmaint N'-MAINTDEL -DELFOLDER "H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL" -DELEXTENSION "bak" -DELUNIT "7201" -DELUNITTYPE "minutes" -DELUSEAGE' IF @ReturnCode <> 0 RAISERROR('Error deleting LiteSpeed backup files.', 16, 1) [SQLSTATE 01000]
LiteSpeed SlsSqlMaint Utility.  Logging on to SQL Server 'SRV-SQLP102' with Windows Authentication  Logged on to SQL Server 'SRV-SQLP102'  Starting maintenance plan 'All ad-hoc plans' on 1/2/2022 2:02:13 AM    [1] Delete files...  Deleting old file: "H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL\SRV-SQLP102_APS_Arieldb_FULL_20211228_010501.bak"  [1] Execution Time: 0 hrs, 0 mins, 0 secs.    End of maintenance plan 'All ad-hoc plans' on 1/2/2022 2:02:14 AM (Success)  D:\MSSQL13.MSSQLSERVER\MSSQL\Binn\slssqlmaint.exe Process Exit Code: 0 (Success) [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:00:01 [SQLSTATE 01000]
Date and time: 2022-01-02 02:02:14 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 02:02:14 [SQLSTATE 01000]
Database: [APS_Arieldb] [SQLSTATE 01000]
State: ONLINE [SQLSTATE 01000]
Standby: No [SQLSTATE 01000]
Updateability: READ_WRITE [SQLSTATE 01000]
User access: MULTI_USER [SQLSTATE 01000]
Recovery model: FULL [SQLSTATE 01000]
Encrypted: No [SQLSTATE 01000]
Is accessible: Yes [SQLSTATE 01000]
Log shipping role: PRIMARY [SQLSTATE 01000]
Differential base LSN: 171335000321564900080 [SQLSTATE 01000]
Last log backup LSN: 171335000319597800001 [SQLSTATE 01000]
Allocated extent page count: 111569000 (871632.812500 MB) [SQLSTATE 01000]
Modified extent page count: 14840 (115.937500 MB) [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 02:02:14 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_create_subdir N'H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL' IF @ReturnCode <> 0 RAISERROR('Error creating directory.', 16, 1) [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:00:00 [SQLSTATE 01000]
Date and time: 2022-01-02 02:02:14 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 02:02:14 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_backup_database @database = N'APS_Arieldb', @filename = N'H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL\SRV-SQLP102_APS_Arieldb_FULL_20220102_020214.bak', @with = 'CHECKSUM', @olrmap = 1, @cryptlevel = 8, @encryptionkey = N'<password>' IF @ReturnCode <> 0 RAISERROR('Error performing LiteSpeed backup.', 16, 1) [SQLSTATE 01000]
SQL> Processed 1160 pages for database 'APS_Arieldb', file 'Arielv81_log' on file 1. SQL> BACKUP DATABASE successfully processed 111593872 pages in 2624.690 seconds (332.163 MB/sec). BACKUP DATABASE successfully processed 111593872 pages in 2624.690 seconds (332.163 MB/sec).   BACKUP ATTACHED FILES successfully processed 1 file(s)   Backup added as file number: 1  Output File(s):  H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL\SRV-SQLP102_APS_Arieldb_FULL_20220102_020214.bak   Native Size: 871899.65 MB Backup Size: 108596.85 MB Attachments: 20.41 MB  CPU Seconds: 2591.97 Environment: Intel(R) Xeon(R) Gold 6134 CPU @ 3.20GHz CPUs: 16 logical, 32 cores, 32 physical packages. [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:45:26 [SQLSTATE 01000]
Date and time: 2022-01-02 02:47:40 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 02:47:40 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_restore_verifyonly @filename = N'H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL\SRV-SQLP102_APS_Arieldb_FULL_20220102_020214.bak', @with = 'CHECKSUM', @encryptionkey = N'<password>' IF @ReturnCode <> 0 RAISERROR('Error verifying LiteSpeed backup.', 16, 1) [SQLSTATE 01000]
LiteSpeed® for SQL Server® Version 8.9.5.213 (64bit) Copyright 2020 Quest Software Inc. ALL RIGHTS RESERVED.    CPU Seconds: 1192.36 Environment: Intel(R) Xeon(R) Gold 6134 CPU @ 3.20GHz CPUs: 16 logical, 32 cores, 32 physical packages. [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:05:33 [SQLSTATE 01000]
Date and time: 2022-01-02 02:53:13 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 02:53:13 [SQLSTATE 01000]
Database context: [master] [SQLSTATE 01000]
Command: DECLARE @ReturnCode int EXECUTE @ReturnCode = dbo.xp_slssqlmaint N'-MAINTDEL -DELFOLDER "H:\MSSQLBackups\SRV-SQLP102\APS_Arieldb\FULL" -DELEXTENSION "bak" -DELUNIT "7201" -DELUNITTYPE "minutes" -DELUSEAGE' IF @ReturnCode <> 0 RAISERROR('Error deleting LiteSpeed backup files.', 16, 1) [SQLSTATE 01000]
LiteSpeed SlsSqlMaint Utility.  Logging on to SQL Server 'SRV-SQLP102' with Windows Authentication  Logged on to SQL Server 'SRV-SQLP102'  Starting maintenance plan 'All ad-hoc plans' on 1/2/2022 2:53:13 AM    [1] Delete files...  [1] Execution Time: 0 hrs, 0 mins, 0 secs.    End of maintenance plan 'All ad-hoc plans' on 1/2/2022 2:53:13 AM (Success)  D:\MSSQL13.MSSQLSERVER\MSSQL\Binn\slssqlmaint.exe Process Exit Code: 0 (Success) [SQLSTATE 01000]
Outcome: Succeeded [SQLSTATE 01000]
Duration: 00:00:01 [SQLSTATE 01000]
Date and time: 2022-01-02 02:53:14 [SQLSTATE 01000]
     [SQLSTATE 01000]
Date and time: 2022-01-02 02:53:14 [SQLSTATE 01000]
     [SQLSTATE 01000]

У меня две работы:

  • Резервное копирование базы данных — USER_DATABASES — ПОЛНОЕ
  • Резервное копирование базы данных — USER_DATABASES — FULL_2

Задания вызывают Quest LiteSpeed ​​для шифрования резервных копий. В заданиях используется следующий код:

EXECUTE [dbo].[DatabaseBackup] 
        @Databases = 'USER_DATABASES', 
        @Directory = N'H:\MSSQLBackups', 
        @BackupType = 'FULL', 
        @BackupSoftware = 'LITESPEED', 
        @Compress = 'Y', 
        @Encrypt = 'Y', 
        @EncryptionAlgorithm = 'AES_256', 
        @EncryptionKey = '<password>', 
        @ObjectLevelRecoveryMap = 'Y', 
        @Verify = 'Y', 
        @CleanupTime = 120, 
        @CheckSum = 'Y', 
        @LogToTable = 'Y', 
        @DatabasesInParallel = 'Y'
0
John K. N. 7 Янв 2022 в 17:15

1 ответ

Тестирование

Я загрузил новейшую версию сценария Ola Maintenance.sql и создал объекты на своем локальном экземпляре ноутбука.

Мне пришлось вручную загрузить файл Queue.sql и файл QueueDatabase.sql, чтобы создать две таблицы в моей базе данных msdb, потому что мое собственное задание OLA DatabaseBackup - USER_DATABASES - FULL не удалось с параметром @DatabasesInParallel='Y' из-за отсутствующих объектов.

После этого я записал вышеупомянутое задание и создал новое идентичное задание, добавив PARALLEL TEST к имени задания.

Теперь у меня было две одинаковые работы:

  • OLA DatabaseBackup - USER_DATABASES - FULL
  • OLA DatabaseBackup - USER_DATABASES - FULL PARALLEL TEST

Затем я пошел дальше и начал обе работы почти одновременно:

Two SQL Server Job Execution Windows displaying jobs with identical parameters running at the same time

Я быстро переключился на таблицу QueueDatabases и запросил содержимое:

Queue Database Table displaying databases being backed up in sequence

Так что выглядело вполне неплохо. Резервное копирование баз данных выполнялось параллельно.

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

Отвечая на ваш вопрос

Мне просто интересно, есть ли у кого-нибудь идеи, почему это может происходить.

Возможно, есть несколько причин, по которым это может происходить.

Причина 1

Первая причина, которая приходит мне на ум, заключается в том, что @DatabasesInParallel был включен (Y) в одном задании, но не (N) в другом.

Причина 2

Скрипты ваших двух заданий по какой-то причине не полностью идентичны. Или у вас может быть два сценария. Один в базе данных msdb, а другой в базе данных master (по умолчанию). Эта причина немного надуманная. Я не мог найти место в коде Олы, где разные параметры задания приводили бы к созданию нескольких резервных копий. Но я только быстро просканировал его код.

Причина 3

В другом задании, выполняющем резервное копирование TLOG, установлен параметр ChangeBackupType='Y', а в задании FULL Backup задан параметр @CleanupMode='BEFORE_BACKUP'. Это приводит к тому, что ПОЛНАЯ резервная копия удаляет файл ПОЛНОЙ резервной копии перед резервным копированием базы данных. В это время срабатывает резервная копия TLOG, и из-за отсутствия ПОЛНОЙ резервной копии создается новая ПОЛНАЯ резервная копия.

Причина 4

Вы нашли ошибку. В этом случае откройте Новый выпуск в репозитории Ola на Github, включая все вы разместили здесь. Вы даже можете связать этот вопрос с проблемой.

Причина 5

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

Причина 6

Другая причина подобного поведения может заключаться в том, что вы запускаете скрипты Ola в выделенной базе данных, и для этой базы данных установлено значение READ_COMMITED_SNAPSHOT_ISOLATION, что приводит к тому, что один процесс читает старые данные. Отключите READ_COMMITED_SNAPSHOT_ISOLATION для этой выделенной базы данных OLA MAINTENANCE.

Причина 7

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

Анализ во время выполнения

Чтобы выявить проблему, попробуйте запросить таблицу QueueDatabase во время ПОЛНОГО резервного копирования и посмотрите, не заметите ли вы какое-либо ненормальное поведение. Как вы можете видеть на моем примере, процедура резервного копирования в целом работает нормально. Каждое задание захватывает базу данных, выполняет действие и должным образом отмечает его завершение.

Удачи!

1
John K. N. 7 Янв 2022 в 18:33
1
Удивительный ответ. Спасибо.
 – 
Ken
8 Янв 2022 в 02:31