SQLGeordie's Blog

Helping the SQL Server community……where i can!

SQL Server CPU’s at 100%? Anyone checked the VAS (Virtual Address Space)??? – Part 2 (The Fix!) — March 9, 2011

SQL Server CPU’s at 100%? Anyone checked the VAS (Virtual Address Space)??? – Part 2 (The Fix!)

First of all I have to make an apology to everyone on SQLServerCentral.com for the lateness of this follow up blog as i know a lot of you have been requesting a follow up to Part 1 which was originally blogged there. I originally wrote (Part 1) over a year ago (recently moved to new blog site) and started work on part 2 but never got to the point of actually finishing it.

In part 1, I wrote about how every now and again our live production sql server’s CPU’s would flatline at 100%. This could happen pretty much anytime of the day, there was no consistency in when it would happen. It was becoming a major issue for the company (and also myself!) because we could not afford any downtime at all and I was running out of ideas as to troubleshoot and ultimately resolve the issue. Then, as if from nowhere, (Slava Ok) came to the rescue when I came across his blogs on VAS in SQL 2005. And this is where I’ll start my follow up by attempting to go through the steps to track, find and resolve the process causing the 100% CPU.

As stated in part 1, I’d been through all the usual checks a DBA would go through when troubleshooting any spikes or flatlines in CPU with no real luck. After reading Slava’s blogs on VAS and tying some of that up to the errors we were receiving in the sql logs, I thought there was a very good chance that VAS was the issue and set about proving that fact.

NOTE: This VAS issue was on a 32bit Windows 2003 Enterprise server with SQL Server 2005 Enterprise (Service Pack 2 CU9) with 4 x 3ghz Xeon processors and 16GB RAM.

First off, in order to try and give a bit of leeway between outages, I looked into the startup parameter –g which sets the amount of MemToLeave (MTL) for sql server. By default this is set to 384MB (256 MB + (0.5 MB x max worker threads [default: 255]) = 384. Calculation taken from Era of Data) so I took the decision to add the startup parameter –g512 to give a bit more for us to play with and hopefully allow longer periods between these outages. I’m not for one minute indicating that this is best practice or the right thing to do in your systems but for us at the time it was a decision we made and ultimately paid off as our outages went from a weekly occurrence, back up to about 1 in 3. The time between outages had been getting shorter and shorter over time, it started as 1 in 4-5 weeks and slowly got more and more frequent which added to the confusion.

So, now with the frequency of the outages less frequent I could then start to track the vas usage and see if I could pinpoint what was causing this issue. First of all I had to capture what the total and max free vas was during the day and look for trends. The script below creates the table to capture the results, the view used (could be a cte if you wish) to get the vas which was taken from Slava’s blog and a modified script taken from Christian Bolton’s blog which captures the server, the max free size, the Total Available and the capture date.


--Create table to capture results
IF EXISTS(SELECT 1 FROM sys.objects WHERE OBJECT_ID = OBJECT_ID(N'VASAvailability') AND type = (N'U'))
DROP TABLE dbo.VASAvailability
CREATE TABLE dbo.VASAvailability
VASAvailabilityID INT IDentity(1,1),
ServerName Varchar(100),
TotalAvailMem_KB INT,
MaxFreeSize_KB INT,
CreatedDate datetime

--Create VAS view
IF EXISTS(SELECT 1 FROM sys.objects WHERE OBJECT_ID = OBJECT_ID(N'vwVas_Summary') AND type = (N'V'))
DROP VIEW dbo.vwVas_Summary
CREATE VIEW dbo.vwVas_Summary AS
Size = Vas_Dump.Size,
Reserved = sum(case (convert (INT,Vas_Dump.Base) ^ 0) when 0 then 0 else 1 end),
Free = sum(case (convert (INT,Vas_Dump.Base) ^ 0x0) when 0 then 1 else 0 end)
--- combine all allocation according with allocation base, don't take into
--- account allocations with zero allocation_base
SELECT CONVERT (varbinary,sum(region_size_in_bytes)) AS Size,
region_allocation_base_address AS Base
FROM sys.dm_os_virtual_address_dump
WHERE region_allocation_base_address<> 0x0
GROUP BY region_allocation_base_address
--- we shouldn't be grouping allocations with zero allocation base
--- just get them as is
SELECT CONVERT (varbinary,region_size_in_bytes), region_allocation_base_address
FROM sys.dm_os_virtual_address_dump
WHERE region_allocation_base_address = 0x0)
as Vas_Dump

Now there are the relevant objects in place to start tracking, I then set about creating a SQL Agent job to run every minute to capture these results. This may have seemed a little extreme as some people have asked if every 5 or 10 minutes would have been sufficient but due to the amount of traffic passing through this system, every minute may not have actually been enough but I stuck with it as a starter. Below is the script I used to insert the results of the vas (Total and Max), all that was required was to create the job and schedule it to run every minute.

INSERT INTO dbo.VASAvailability(ServerName,TotalAvailMem_KB,MaxFreeSize_KB,CreatedDate)
SELECT  @@ServerName, ,SUM(CONVERT(BIGINT , Size) * Free) / 1024 AS [Totalavailmem,KB] ,CAST(MAX(Size) AS BIGINT) / 1024 AS [Maxfreesize,KB] ,getdate() FROM    vwVas_Summary WHERE   Free <> 0

Over the next couple of weeks I monitored the results of the VAS trying to look for any trends or patterns as to when the VAS would drop and not be reclaimed. The nature of VAS shows that a process will claim a portion of it but in theory should release it once finished with it. At first I couldn’t find a particular day or even time as to when the total VAS reduced significantly and never came back. As with the flatlined cpu’s, it seemed to be happening on any day and at any time. By this time I’d lost most of my hair due to ripping it out and was on the verge of launching our system out the window!

All I could do from here was try and take sample times from when the vas dropped and try to investigate what processes were running at that time. The godsend at the time was having SQL Sentry’s Performance Advisor for SQL Server as that allowed me to quickly interpret what was running at any given time and saved me god knows how long in setting up server side traces etc to monitor this. A few of the selected time periods I chose were inconclusive due to the amount of traffic going through our system at those times, it could have been any one of over 1000 different procedures – gutted! Over the next few weeks I continued to monitor the results and finally started to see a trend becoming apparent. We seemed to lose a large portion of VAS on a Monday evening which I had kind of discredited at first due to it not being every Monday evening and the fact there wasn’t anything major running at that time…………..or so I thought.

Every evening we had a large overnight XML file import process which ran at various times depending on when we received the file from a 3rd party. This could be from 8pm until 2am the following morning. What I hadn’t thought of is that this process didn’t run over a weekend so on a Monday we had a file which was 3 times the normal size to cater for 3 days worth of data, bearing in mind that a normal size file was around 250MB, this meant that file on a Monday evening would be ~700MB. Now, this normally wouldn’t present an issue as the process ran a procedure using sp_xml_preparedocument and sp_xml_removedocument to clean up after itself, but what I wasn’t aware of until speaking with the development team was that their service sat waiting for this file and as soon as it saw the file it’d begin processing it – even though it hadn’t fully downloaded! Being XML, this import process would obviously fail due to an incomplete file and this could potentially happen 3 or 4 times during the 20-30mins its take to download the file (very slow uplink from 3rd party).

Can you see where I’m going with this?

What I uncovered was that each time the file was being (attempted) imported, it would run the sp_xml_preparedocument and attempt to process the incomplete file and ultimately bomb out, without running the sp_xml_removedocument due to error handling being handled by COM+ and nothing in the stored procedure. Something I actually learned from this was that rolling back via COM+ doesn’t “unprepare” the XML document, the only way you can do this is to deallocate it via the sp_xml_removedocument. We amended the process to handle reading the XML file by using a simple Try and Catch within the procedure like this:

Do import / sp_xml_preparedocument
EXECUTE sp_xml_removedocument @iDoc
-- Raise an error with the details of the exception
DECLARE @ErrMsg nvarchar(4000), @ErrSeverity int
SELECT @ErrMsg = ERROR_MESSAGE() ,@ErrSeverity = ERROR_SEVERITY()   RAISERROR(@ErrMsg, @ErrSeverity, 1)

And that was that! At the time of writing Part 1, we hadn’t experienced the issue within 2 months by implementing this error handling. At the time of writing this (well, when I started it) it was over 6 months and we never experienced the same issue of 100% CPU due to low VAS. We continued to monitor VAS by keeping the agent job running (at a reduced frequency) and having our bespoke proactive monitoring system alert us when it fell below 30MB to warn us that we may be experiencing memory pressure caused by low VAS and our systems are potentially going to go skits!

SQL Server CPU’s at 100%? Anyone checked the VAS (Virtual Address Space)??? —

SQL Server CPU’s at 100%? Anyone checked the VAS (Virtual Address Space)???

As a DBA, you can almost guarantee that at some point you’ll experience a server maxing out its CPU’s at 100%. Here is my latest experience with this situation which I’ve decided to blog as I found whilst researching that there isn’t that much in the way of documentation for this. Hope it helps many others out there……

This issue was on a Windows 2003 Enterprise server with SQL Server 2005 Enterprise (Service Pack 2 CU9) with 4 x 3ghz Xeon processors and 16GB RAM.


Every now and again (roughly 2 weeks) our live production sql server’s CPU’s would flatline at 100%. This could happen pretty much anytime of the day, there was no consistency in when it would happen, could be first thing in the morning, mid-afternoon or late evening.


Instinct and experience told me that CPU’s at 100% will no doubt be an issue with a big process that probably shouldn’t be running during peak times (AV scan or the likes), a query with possibly a lot of big table / index scans or hash joins. As I knew we don’t run AV scans during peak times and that from task manager I could see that the biggest CPU hogger was sql server itself, my primary focus was to investigate the procedures currently running. So, knowing that only myself and the technical architect have access to the live production environment and I knew that I wasn’t running anything and neither was he, it had to be something being ran from our in-house VB.net system.

Starting from the beginning, I started simple with a sp_who2 and sp_lock. These themselves could take up to 30seconds to return any output! When they did the number of processes running was about normal but the one thing that did stand out was the number of blocked processes. Since there were a lot of procedures blocking a number of other processes I decided to look into sysprocesses for processes and queries that were long running, open transactions and high CPU time to see if anything stood out as being the problem. However, due to the cpu’s being at 100%, EVERYTHING was running slow. Queries that normally took less than 500ms were taking up to 1min which as you can imagine is not acceptable in a live environment. Nothing seemed to be standing out as an issue, those that seemed like potential candidates were killed (risky I know). The daily profiler we run was difficult to research because of the above mentioned issue, every single query that was going through the system was off the scale. With this in mind, I stopped the Profiler and even tried restarting the agent to see if it were a transactional replication issue – but still the cpu’s at 100%.

So, to re-cap.

  • There are no external / 3rd party processes running on this box as its a dedicated sql server. The process with high cpu was sql server itself.
  • There were no long running queries / high cpu time that stood out, almost every procedure had an open transaction as they were taking so long to process.

The only option I had was to fail the server over as I now had department heads lined up at my desk asking “is it fixed yet?, is it fixed yet?, is it fixed yet?”. Sure enough, fail the servers over or restart the sql service and all is well again.

Checking the sql logs show nothing other than the fact that I’ve failed the server over and that the every 30min (Redgate) sql log backup’s failed, so no luck there…..or so I thought (see further down). I tried trailing the profiler around the time of high cpu issue beginning but nothing jumping out. After this had happened a couple of times this was becoming a very big problem. I was in a very difficult situation, nothing I searched after the incidents showed anything and I had roughly 5minutes to investigate whilst the issue was apparent.

My next train of thought was a memory leak. I trawled Microsoft and google looking for any patches or kb’s referring to memory leaks but all I found were either related to SQL 2000, fixed in earlier sql server cumulative updates to what we had installed and the one I found relating to McAfee turned out to be a dead end as we had a later version to that mention as having the memory leak issues.

I decided to take the slight performance hit and run Disk, CPU and memory perfmon’s as well as running quests spotlight to monitor this situation. Once again, when the high CPU issue arose all I got was basically that; CPU’s maxed out. Matching perfmon to the profiler ran didn’t bring anything to light. By now I was running out of ideas. I tried turning Hyper Threading off, restricting affinity to 2cpu’s instead of 4 but still no luck – every couple of weeks all the cpu’s still maxing out!

So, I once again returned to the log files and delved further into the one common theme I could find when this issue arose – RedgateVDI / log backup failure’s.

The error log (cut down) showed:

2009-01-19 17:15:00.59 spid435 Error: 18210, Severity: 16, State: 1.
2009-01-19 17:15:00.59 spid435 BackupVirtualDeviceSet::Initialize: Request large buffers failure on backup device ‘SQLBACKUP_C9D0A658-E6F1-4A03-8CC7-AC8466A5B202’. Operating system error 0x8007000e(Not enough storage is available to complete this operation.)

This was initially seen (by myself and colleagues) as a red-herring, due to there being more than enough storage available to initiate the backups. Looking a bit further (1000’s of errors output during this failure) I found errors such as:

Event Type: Error
Event Source: SQLVDI
Event Category: None
Event ID: 1
Date: 14/02/2009
Time: 2:10:03 PM
User: N/A
Computer: SqlBox1
SQLVDI: Loc=BufferAreaManager::MapBuffers. Desc=Out Of Address Space. ErrorCode=(8)Not enough storage is available to process this command.
. Process=512. Thread=2500. Server. Instance=SQL2000. VD=Global\SQLBACKUP_690D9E54-3147-4530-B037-7BA589B1B005_SQLVDIMemoryName_

Virtual Address Space? Aha! Now we’re getting somewhere. I searched Redgate for this VDI error and came up with this forum post: http://www.red-gate.com/messageboard/viewtopic.php?t=4240&postdays=0&postorder=asc&start=0

Now, although I was having similar issues relating to VDI, we didn’t seem to be having the common issue of 100% cpu’s but I did decide to monitor the server using EXEC maser..sqbmemory and this proved to be very interesting. When our server was maxing out at 100%, I ran this procedure and low and behold, the maximum free block of VAS was 3mb! I restarted the sql service and checked it again and it was back to circ 300mb.

This lead me to believe that it was almost certainly a VAS pressure issue we were experiencing and possibly created by redgate sql backup. I decided to research VAS further and found a brilliant blog by Slava Oks which can be found at: http://blogs.msdn.com/slavao/

I decided to monitor VAS by capturing the free blocks and total available every minute to see if I can trap what is actually causing the VAS to be eaten up. Over the next few weeks it became apparent that we had a large xml file (> 500mb) which was imported (using sp_xml_preparedocument and sp_xml_removedocument) every evening and sometime during this import the total VAS available dropped drastically. Taking this a step further, I decided to capture the VAS at every step of this import and found that one section seemed to be the culprit. The ins and outs of this are beyond the scope of this post but I may blog it in the future.

So, amend the procedure and all VAS issues are now resolved – we’ve not had a 100% cpu issue in over two months now (touch wood!). I am still monitoring the VAS (alerts put in place for if it drops too low) but I’m now 99.9% certain (there’s always room for doubt 🙂 ) that this issue is now resolved. Took a while but got there in the end!!!

Anyone else had similar issues?

Below I have listed a couple of links to descriptions of VAS for you to either brush up on or even learn a thing or two.

Virtual Address Space (VAS):