First attempt at every backup fails. Second attempt works.

Bernard SheppardBernard Sheppard Posts: 53
edited July 27, 2006 9:33AM in SQL Backup Previous Versions
I'm getting a VDI error on the first attempt to run a backup followed by a memory profile, and the second attempt works every time.

Here's sample output:
27/07/2006 3:56:33 pm: Backing up Wiki (transaction log) to: 
  D:\Program Files\Microsoft SQL Server\MSSQL\Backup\LOG_ADELN040_(local)_Wiki_20060727_155633_01.sqb
  D:\Program Files\Microsoft SQL Server\MSSQL\Backup\LOG_ADELN040_(local)_Wiki_20060727_155633_02.sqb

27/07/2006 3:56:33 pm: BACKUP LOG [Wiki]  TO DISK = 'D:\Program Files\Microsoft SQL Server\MSSQL\Backup\LOG_ADELN040_(local)_Wiki_20060727_155633_01.sqb', DISK = 'D:\Program Files\Microsoft SQL Server\MSSQL\Backup\LOG_ADELN040_(local)_Wiki_20060727_155633_02.sqb' WITH NAME = '<AUTO>', DESCRIPTION = '<AUTO>', NO_TRUNCATE, INIT, ERASEFILES = 26h, MAILTO_ONERROR = 'myemail@mycompany.com', COMPRESSION = 3, THREADS = 2

27/07/2006 3:56:34 pm: VDI error 1010: Failed to get configuration from server.  Check that the SQL Server instance is running, and that you have the SQL Server Systems Administrator server role.  Error code:  (-2139684860: An abort request is preventing anything except termination actions.)
27/07/2006 3:56:34 pm: SQL error 3013: BACKUP LOG is terminating abnormally.
27/07/2006 3:56:34 pm: 
27/07/2006 3:56:35 pm: Memory profile
27/07/2006 3:56:35 pm: Type             Maximum     Minimum     Average     Blk count   Total      
27/07/2006 3:56:35 pm: ---------------- ----------- ----------- ----------- ----------- -----------
27/07/2006 3:56:35 pm: Commit           64471040    4096        58368       23119       1349410816 
27/07/2006 3:56:35 pm: Reserve          4128768     4096        27121       21572       585056256  
27/07/2006 3:56:35 pm: Free             11993088    4096        359714      592         212951040  
27/07/2006 3:56:35 pm: Private          64471040    4096        42944       43893       1884971008 
27/07/2006 3:56:35 pm: Mapped           1019904     4096        92966       66          6135808    
27/07/2006 3:56:35 pm: Image            7569408     4096        59235       732         43360256   
27/07/2006 3:56:35 pm: 
27/07/2006 3:56:35 pm: 
27/07/2006 3:56:35 pm: Warning 300: Backup failed.  Retry attempt: 1
27/07/2006 3:56:37 pm: BACKUP LOG [Wiki]  TO DISK = 'D:\Program Files\Microsoft SQL Server\MSSQL\Backup\LOG_ADELN040_(local)_Wiki_20060727_155633_01.sqb', DISK = 'D:\Program Files\Microsoft SQL Server\MSSQL\Backup\LOG_ADELN040_(local)_Wiki_20060727_155633_02.sqb' WITH NAME = 'Database (Wiki), 27/07/2006 3:56:33 pm', DESCRIPTION = 'Backup on 27/07/2006 3:56:33 pm  Server: ADELN040  Database: Wiki', NO_TRUNCATE, INIT, ERASEFILES = 26h, MAILTO_ONERROR = 'myemail@mycompany.com', COMPRESSION = 3, THREADS = 2

27/07/2006 3:56:37 pm: Backup data size    : 7.188 MB
27/07/2006 3:56:37 pm: Compressed data size: 818.500 KB
27/07/2006 3:56:37 pm: Compression rate    : 88.88%

Processed 734 pages for database 'Wiki', file 'Wiki_Log' on file 1.
BACKUP LOG successfully processed 734 pages in 0.282 seconds (21.313 MB/sec).
--------------------------------------------------------------------------------

27/07/2006 3:56:40 pm: Mail sent successfully to: myemail@mycompany.com

Here's the relevant section of VDI.log:
----------------------------------------------
2006/07/27 15:56:34 pid(4384) tid(1428)
Error on Global\SQLBACKUP_428DB65D-6B48-4695-B693-87E73E8698E6
Error at ServerBufferAreaManager::Allocate: Map buffers Status Code: 8, x8
Explanation: Not enough storage is available to process this command.



----------------------------------------------
2006/07/27 15:56:34 pid(4384) tid(1428)
Error on Global\SQLBACKUP_428DB65D-6B48-4695-B693-87E73E8698E6
Error at TriggerAbort: invoked

----------------------------------------------
2006/07/27 15:56:34 pid(4384) tid(1428)
Error on Global\SQLBACKUP_428DB65D-6B48-4695-B693-87E73E8698E6
Error at SVDS::EndConfiguration: Commit buffers Status Code: -2147024888, x80070008
Explanation: Not enough storage is available to process this command.



----------------------------------------------
2006/07/27 15:56:34 pid(9052) tid(21264)
Error on Global\SQLBACKUP_428DB65D-6B48-4695-B693-87E73E8698E6
Error at CVDS::GetConfiguration: SignalAbort

----------------------------------------------
2006/07/27 15:56:34 pid(4384) tid(1428)
Error on Global\SQLBACKUP_428DB65D-6B48-4695-B693-87E73E8698E6
Error at TriggerAbort: invoked

----------------------------------------------
2006/07/27 15:56:34 pid(9052) tid(21264)
Error on Global\SQLBACKUP_428DB65D-6B48-4695-B693-87E73E8698E6
Error at TriggerAbort: invoked

----------------------------------------------
2006/07/27 15:56:34 pid(4384) tid(1428)
Error on Global\SQLBACKUP_428DB65D-6B48-4695-B693-87E73E8698E6
Error at TriggerAbort: invoked

My guess is that the auto step down in MaxTransferSize is being invoked, but my concern is that the process is failing as far as SQL Backup is concerned - at least in terms of it firing a MAILTO_ONERROR notification.

Is this expected behaviour or is something else going on.

If it were up to me, I'd expect to see these messages if I had MAILTO_ONWARNING set, but not with MAILTO_ONERROR :)

Thanks

Bernard

Comments

  • Brian DonahueBrian Donahue Posts: 6,590 Bronze 1
    Hi Bernard,

    The suggestion about having an option not to email warnings is already on our list of things to do.

    The backup is behaving normally, so I don't think it's good to worry users in this way over a normal process of stepping down the max transfer size for the backup when buffer issues occur.
Sign In or Register to comment.