Failed Virtual Allocate Bytes: FAIL_VIRTUAL_RESERVE

mrclod

The backup worked locally, but appears to have failed to move the copy. I have 2TB of free space and the backup is about 40GB compressed. Backup Pro 5.4 running on a cluster.

Have included information from the sql server logs below.

Clues???




2009-09-08 20:00:34.51 spid449 Failed Virtual Allocate Bytes: FAIL_VIRTUAL_RESERVE 1245184
2009-09-08 20:00:34.62 spid449
Memory Manager
VM Reserved = 1750848 KB
VM Committed = 313416 KB
AWE Allocated = 27787264 KB
Reserved Memory = 1024 KB
Reserved Memory In Use = 0 KB 2009-09-08 20:00:34.62 spid449
Memory node Id = 0
VM Reserved = 1746688 KB
VM Committed = 309408 KB
AWE Allocated = 27787264 KB
SinglePage Allocator = 490032 KB
MultiPage Allocator = 21280 KB 2009-09-08 20:00:34.62 spid449
MEMORYCLERK_SQLGENERAL (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 11384 KB
MultiPage Allocator = 3480 KB 2009-09-08 20:00:34.62 spid449
MEMORYCLERK_SQLBUFFERPOOL (Total)
VM Reserved = 1614968 KB
VM Committed = 275576 KB
AWE Allocated = 27787264 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 0 KB
MultiPage Allocator = 7048 KB 2009-09-08 20:00:34.62 spid449
MEMORYCLERK_SQLQUERYEXEC (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 16 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.62 spid449
MEMORYCLERK_SQLOPTIMIZER (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 273864 KB
MultiPage Allocator = 2064 KB 2009-09-08 20:00:34.62 spid449
MEMORYCLERK_SQLUTILITIES (Total)
VM Reserved = 840 KB
VM Committed = 840 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 80 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SQLSTORENG (Total)
VM Reserved = 2688 KB
VM Committed = 2688 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 10744 KB
MultiPage Allocator = 232 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SQLCONNECTIONPOOL (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 23704 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SQLCLR (Total)
VM Reserved = 100416 KB
VM Committed = 3808 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 736 KB
MultiPage Allocator = 1024 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SQLSERVICEBROKER (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 80 KB
MultiPage Allocator = 192 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SQLHTTP (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SNI (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 4416 KB
MultiPage Allocator = 16 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_FULLTEXT (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 160 KB
MultiPage Allocator = 88 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SQLXP (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 16 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_BHF (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 2536 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_HOST (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 80 KB
MultiPage Allocator = 80 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SOSNODE (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 7616 KB
MultiPage Allocator = 6448 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_FULLTEXT_SHMEM (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 64 KB
SM Committed = 64 KB
SinglePage Allocator = 0 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
MEMORYCLERK_SQLSERVICEBROKERTRANSPORT (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 24 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_OBJCP (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 2552 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_SQLCP (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 6200 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_PHDR (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 59016 KB
MultiPage Allocator = 416 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_XPROC (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 40 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_TEMPTABLES (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 24 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_NOTIF (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 16 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_VIEWDEFINITIONS (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 112 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_XMLDBTYPE (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_XMLDBELEMENT (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_XMLDBATTRIBUTE (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_STACKFRAMES (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 0 KB
MultiPage Allocator = 8 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_BROKERTBLACS (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 80 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_BROKERKEK (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_BROKERDSH (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_BROKERUSERCERTLOOKUP (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_BROKERRSB (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_BROKERREADONLY (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 32 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_BROKERTO (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 8 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_EVENTS (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 16 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
CACHESTORE_SYSTEMROWSET (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 296 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
USERSTORE_SCHEMAMGR (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 2832 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
USERSTORE_DBMETADATA (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 4288 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
USERSTORE_TOKENPERM (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 4560 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
USERSTORE_OBJPERM (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 664 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
USERSTORE_SXC (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 864 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
OBJECTSTORE_LBSS (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 200 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
OBJECTSTORE_SNI_PACKET (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 70632 KB
MultiPage Allocator = 48 KB 2009-09-08 20:00:34.63 spid449
OBJECTSTORE_SERVICE_BROKER (Total)
VM Reserved = 0 KB
VM Committed = 0 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 256 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449
OBJECTSTORE_LOCK_MANAGER (Total)
VM Reserved = 4096 KB
VM Committed = 4096 KB
AWE Allocated = 0 KB
SM Reserved = 0 KB
SM Committed = 0 KB
SinglePage Allocator = 1784 KB
MultiPage Allocator = 0 KB 2009-09-08 20:00:34.63 spid449 Buffer Distribution: Stolen=49315 Free=41247 Cached=11939
Database (clean)=1963499 Database (dirty)=1407399
I/O=0, Latched=9 2009-09-08 20:00:34.63 spid449 Buffer Counts: Committed=3473408 Target=3473408 Hashed=3370907
Internal Reservation=33484 External Reservation=0
Stolen Potential=97798
Min Free=296 Visible=167424
Available Paging File=6106828800
2009-09-08 20:00:34.63 spid449 Procedure Cache: TotalProcs=10 TotalPages=8528 InUsePages=60 2009-09-08 20:00:34.63 spid449 Process physical/virtual memory pressure: 0/0 System physical memory pressure: 0 2009-09-08 20:00:34.63 spid449 Global Memory Objects:
Resource= 361
Locks= 226
SE Schema Mgr= 353
SQLCache= 802
Replication= 136
ServerGlobal= 26
XPGlobal= 2
Xact= 1132
SETLS= 8
DatasetMemObjs= 16
SubpDescPmos= 8
SortTables= 2 2009-09-08 20:00:34.63 spid449 Query Memory Objects: Grants=0 Waiting=0 Maximum=61461 Available=61461 Limit=86925 2009-09-08 20:00:34.63 spid449 Query Memory Objects: Next Request=0 Waiting For=0 Cost=0 Timeout=0 Wait Time=0 Last Target=91500 2009-09-08 20:00:34.63 spid449 Small Query Memory Objects: Grants=0 Waiting=0 Maximum=4223 Available=4223 Limit=4223 2009-09-08 20:00:34.63 spid449
Optimization Queue
Overall Memory = 1099284480 Target Memory = 960536576 Last Notification = GROW Timeout = 6 Early Termination Factor = 5
2009-09-08 20:00:34.63 spid449
Small Gateway
Configured Units = 32 Available Units = 0 Acquires = 32
Waiters = 124 Threshold Factor = 250000 Threshold = 250000
2009-09-08 20:00:34.63 spid449
Medium Gateway
Configured Units = 8 Available Units = 0 Acquires = 8
Waiters = 24 Threshold Factor = 12 Threshold = 2501397
2009-09-08 20:00:34.63 spid449
Big Gateway
Configured Units = 1 Available Units = 0 Acquires = 1
Waiters = 7 Threshold Factor = 8 Threshold = 15008384
2009-09-08 20:00:34.63 spid449
MEMORYBROKER_FOR_CACHE
Allocations = 11943
Rate = -19
Target Allocations = 79664
Future Allocations = 0
Last Notification = GROW 2009-09-08 20:00:34.63 spid449
MEMORYBROKER_FOR_STEAL
Allocations = 49311
Rate = 202
Target Allocations = 117253
Future Allocations = 0
Last Notification = GROW 2009-09-08 20:00:34.63 spid449
MEMORYBROKER_FOR_RESERVE
Allocations = 0
Rate = 0
Target Allocations = 97615
Future Allocations = 29875
Last Notification = GROW 2009-09-08 20:00:34.63 spid449 Error: 701, Severity: 17, State: 123.
2009-09-08 20:00:34.63 spid449 There is insufficient system memory to run this query.
2009-09-08 20:00:36.24 spid325 Error: 18210, Severity: 16, State: 1.
2009-09-08 20:00:36.24 spid325 BackupVirtualDeviceSet::Initialize: Request large buffers failure on backup device 'SQLBACKUP_C5BD7A3E-A00C-4E8F-A78D-B4D8C17E1187'. Operating system error 0x8007000e(Not enough storage is available to complete this operation.).
2009-09-08 20:00:36.27 spid325 Error: 18210, Severity: 16, State: 1.
2009-09-08 20:00:36.27 spid325 BackupVirtualDeviceSet::Initialize: Request large buffers failure on backup device 'SQLBACKUP_C5BD7A3E-A00C-4E8F-A78D-B4D8C17E1187'. Operating system error 0x8007000e(Not enough storage is available to complete this operation.).
[/i]

mrclod

Looks like our IT department didn't specify a max memory, setting SQL Server to have a max of 29G of the 32G on the system.

Not sure if that will do it, but not finding a lot of definitive information on the subject.

mrclod

I've tried reducing threads. Still get these errors. A second attempt (as specified for the backup job to do) is successful. Just doing a LOG backup at this point.

Threads are down to 2 and MAXTRANSFERSIZE is 1024.

Going to attempt to move the MAXTRANSFERSIZE down just a notch to see what happens. Not sure why a chunk of memory cannot be found in 3GB of free memory.

Does 6.2 address any of these issues??




2009-09-10 14:00:01.27 spid291 Error: 18210, Severity: 16, State: 1.
2009-09-10 14:00:01.27 spid291 BackupVirtualDeviceSet::Initialize: Request large buffers failure on backup device 'SQLBACKUP_FCBD0467-A16F-4C07-B32F-B2B1674D3188'. Operating system error 0x8007000e(Not enough storage is available to complete this operation.).

2009-09-10 14:00:01.27 spid291 Error: 18210, Severity: 16, State: 1.
2009-09-10 14:00:01.27 spid291 BackupVirtualDeviceSet::Initialize: Request large buffers failure on backup device 'SQLBACKUP_FCBD0467-A16F-4C07-B32F-B2B1674D3188'. Operating system error 0x8007000e(Not enough storage is available to complete this operation.).

mrclod

Set Threads to 3, MAXTRANSFERSIZE to 960 on the LOG backup only.

A reply from RedGate would be nice so I could stop taking stabs in the dark at this.

petey

Could you please post the contents of the SQL Backup log file for that backup? By default, the log files are stored in C:\Documents and Settings\All Users\Application Data\Red Gate\SQL Backup\Log\<instance name>.

Thanks.

mrclod

This is an intermittent issue. Some days no error(s), others 5-8 identical. Most of the time the retry works and gets a copy moved for us, other times, the copy does not happen. This server is the one that is most problematic. I do see this occasionally on other servers.




SQL Backup log file 5.4.0.55

-SQL "BACKUP LOG [prod1] TO DISK = 'U:\BACKUPS\<database>\<AUTO>.sqb' WITH ERASEFILES_ATSTART = 7, MAILTO_ONERROR = 'XXXXXXXXXXXX', MAXTRANSFERSIZE = 983040, PASSWORD = 'XXXXXXXXXXXX', COMPRESSION = 3, COPYTO = '\\dbbackup\DatabaseBackups\P5\S3\<database>\', KEYSIZE = 256, THREADCOUNT = 3, VERIFY "

---

ERRORS AND WARNINGS

---

9/14/2009 4:00:00 PM: Backing up prod1 (transaction log) on DBC instance to:
9/14/2009 4:00:00 PM: U:\BACKUPS\prod1\LOG_prod1_20090914_160000.sqb

9/14/2009 4:00:05 PM: BACKUP LOG [prod1] TO VIRTUAL_DEVICE = 'SQLBACKUP_F27195FA-DE91-490F-96B3-493FF1C6794D', VIRTUAL_DEVICE = 'SQLBACKUP_F27195FA-DE91-490F-96B3-493FF1C6794D01', VIRTUAL_DEVICE = 'SQLBACKUP_F27195FA-DE91-490F-96B3-493FF1C6794D02' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 983040, NAME = N'Database (prod1), 9/14/2009 4:00:00 PM', DESCRIPTION = N'Backup on 9/14/2009 4:00:00 PM Server: dbp1 Database: prod1', FORMAT

9/14/2009 4:00:05 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.)
9/14/2009 4:00:06 PM: SQL error 3013: BACKUP LOG is terminating abnormally.
9/14/2009 4:00:06 PM: SQL error 18210: BackupVirtualDeviceSet::Initialize: Request large buffers failure on backup device 'SQLBACKUP_F27195FA-DE91-490F-96B3-493FF1C6794D'. Operating system error 0x8007000e(Not enough storage is available to complete this operation.).
9/14/2009 4:00:06 PM:
9/14/2009 4:00:06 PM: Memory profile
9/14/2009 4:00:06 PM: Type Maximum Minimum Average Blk count Total
9/14/2009 4:00:06 PM:

---

---

---

---

---

---

9/14/2009 4:00:06 PM: Commit 263979008 4096 50353 29114 1465991168
9/14/2009 4:00:06 PM: Reserve 8318976 4096 23136 27367 633167872
9/14/2009 4:00:06 PM: Free 4194304 4096 161401 299 48259072
9/14/2009 4:00:06 PM: Private 263979008 4096 35346 55693 1968533504
9/14/2009 4:00:06 PM: Mapped 1060864 4096 98986 78 7720960
9/14/2009 4:00:06 PM: Image 24948736 4096 173105 710 122904576
9/14/2009 4:00:06 PM:
9/14/2009 4:00:19 PM:
9/14/2009 4:00:19 PM: Verifying files:
9/14/2009 4:00:19 PM: U:\BACKUPS\prod1\LOG_prod1_20090914_160000.sqb
9/14/2009 4:00:19 PM:
The backup set on file 1 is valid.
9/14/2009 4:00:35 PM: Copied U:\BACKUPS\prod1\LOG_prod1_20090914_160000.sqb to \\dbbackup\DatabaseBackups\P5\S3\prod1\LOG_prod1_20090914_160000.sqb.

---

PROCESSES COMPLETED SUCCESSFULLY

---

9/14/2009 4:00:06 PM: Warning 300: Backup failed. Retry attempt: 1
9/14/2009 4:00:08 PM: BACKUP LOG [prod1] TO VIRTUAL_DEVICE = 'SQLBACKUP_B8390B26-75C8-44D9-9778-A7928A987C89', VIRTUAL_DEVICE = 'SQLBACKUP_B8390B26-75C8-44D9-9778-A7928A987C8901', VIRTUAL_DEVICE = 'SQLBACKUP_B8390B26-75C8-44D9-9778-A7928A987C8902' WITH BUFFERCOUNT = 18, BLOCKSIZE = 65536, MAXTRANSFERSIZE = 458752, NAME = N'Database (prod1), 9/14/2009 4:00:00 PM', DESCRIPTION = N'Backup on 9/14/2009 4:00:00 PM Server: dbp1 Database: prod1', FORMAT

9/14/2009 4:00:19 PM: Backup data size : 350.688 MB
9/14/2009 4:00:19 PM: Compressed data size: 98.774 MB
9/14/2009 4:00:19 PM: Compression rate : 71.83%

Processed 43877 pages for database 'prod1', file 'cyracle_Log' on file 1.
BACKUP LOG successfully processed 43877 pages in 9.602 seconds (37.433 MB/sec).
9/14/2009 4:00:36 PM: Mail sent successfully to: XXXXXXXXXXXX

petey

Thanks for posting the log.

The log doesn't indicate any issue with the copying process. There is an issue with the amount of free memory, where the 1st backup attempt failed, while the 2nd succeeded because SQL Backup lowered its memory requirements.

9/14/2009 4:00:06 PM: Type Maximum Minimum Average Blk count Total
9/14/2009 4:00:06 PM:

---

---

---

---

---

---

9/14/2009 4:00:06 PM: Free 4194304 4096 161401 299 48259072

The log shows that the largest contiguous block of free memory is 4194304 bytes in size. You actually have 48259072 bytes of total free memory, but they are spread over 299 blocks, which means a very fragmented address space.

If you want to, you can monitor this memory allocation by running the sqbmemory extended stored procedure e.g.

EXEC master..sqbmemory

Monitored over time, you may discover what exactly is fragmenting the free memory space.

mrclod

Would the value of MemToLeave affect this by chance since redgate routines appear to be external stored procedures?

petey

Increasing the MemToLeave value using the -g switch is an option, but may not address the issue entirely.

During a SQL Backup backup, SQL Server requires large blocks of memory from the MemToLeave region to service the backup request. Your MemToLeave region has enough memory in total (~46 MB), but because they are fragmented, the average size is only 157 Kb. Some other component appears to be fragmenting this memory space. Could be some CLR routines, extended stored procedures etc, in which case increasing the MemToLeave region would just delay the fragmentation effect. I don't know if its possible to monitor what exactly is using the MemToLeave memory space.