Tech Support > Microsoft Windows > Windows Server > server generates Delayed Write errors copying Very large Files
server generates Delayed Write errors copying Very large Files
Posted by Phil Lewis on May 24th, 2008


Apologies as this turned out to be rather lengthy....

I run a development engineering lab for a financial services company and we
are running into a rather peculiar but very troubling problem on some of our
performance servers when copying, moving or backing up very large files,
i.e. files greater than about 52 Gigabytes in size (yes GB not MB).
Primarily these are SQL Server database files but we also see the same
problems copying or relocating large Virtual Server Hard Drive files of that
size or larger.
The problem is actually an old one that I think has not been dealt with, the
end result for us on Windows Server 2000 and Windows Server 2003 R2 is that
after copying about 52 Gbytes of the file, Windows starts reporting "Windows
delayed write" errors and at that point the file copy collapses and stops.
Although the system reports the copy is still running, no further data is
being successfully copied. All the file IO and other windows processes
slowdown considerably (more on this in a little bit). In each case where a
delayed write error is generated, Event Viewer shows the first error as
being event ID 50 and or Event 26. The problem is seen when using Drive
letters and UNC paths and we asked about hotfixes for Server 2003 SP2 but
were told by support there were none as the fix described in KB Article
890352 [ http://support.microsoft.com/kb/890352/ ] was rolled into SP2 and
did not apply to our issue.

We have only recently begun to see these problems because until recently
most of our performance testing model used fairly small working sets for
data (typically under 100GB total) and thus each file-group in our databases
was less than 40GB so we never really saw a problem. I've seen this problem
on ALL versions of Windows including Server 2008. In the server 2008 case,
the O/S collapses completely and cannot be shutdown.In most cases we have to
power-off the server to get the problem system to recover, no delayed write
error is reported on server 2008.

I've tested this on a variety of servers (listed next) and in as many cases
as possible I tested on multiple servers with the same config and with
different O/S editions. I also tested one of the servers that was
experiencing the problems first, using small files (files from 1byte up to
40 GigaBytes in size). The test set I use is approx 870GB in total size and
has been continuously copying for about 40 days now continuously on this
server, I think at last check it had copied around 2,973 Terabytes of data
on this server, all without error.

Primary Test Servers and configurations
HP ML570 Quad Xeon w/ 16GB Ram and 1.2TBytes local storage + 3.4TB SAN
storage on a Nexsan Sataboy Box. WinSvr 2003R2 SP2 x86 and x64.
HP DL580 Dual Xeon w/8Gb or 16Gb Ram and 1.2TB Local Storage + 3.4 TB SAN
Storage on a Nexsan Sataboy Box. WinSvr 2003R2 SP2 x86 and x64.
HP DL380 G4p Dual Xeon w/4Gb Ram and 300GB Local Storage + 3.4 TB SAN
Storage on a Nexsan Sataboy Box. WinSvr 2003R2 SP2 x86
DELL 2950 dual quad Core 2.83Ghz w/32 GB Ram 320GB Local Storage 4.2TB on an
EMC AX150 SAN and 3.4 TB SAN Storage on a Nexsan Sataboy Box. WinSvr 2003R2
SP2 x86 and x64, Win Svr 2008 x64.
DELL 2950 dual quad Core 2.5Ghz w/4 GB Ram 140GB Local Storage 4.2TB on an
EMC AX150 SAN and 3.4 TB SAN Storage on a Nexsan Sataboy Box. WinSvr 2003R2
SP2 x86 and WinSvr2008 x86
Dell Precision 460T wkstation Dual Xeon 2.4Ghz with 4GB Ram and 1TB of local
storage (SATA) 3.4 TB SAN Storage on a Nexsan Sataboy Box via iSCSI WinSvr
2003R2 SP2 x64
With the exception of the ML570 I've tested on multiple servers of the same
type. All servers have succeeded in copying large volumes of files 40Gb and
smaller.

On our HPs all drives are SCSI hot swappable. Either 10 or 15K. We don't mix
spindle speeds in raid groups. On our Dells, all local drives are SAS, on
the EMC AX150 all drives are are SATA and on the SATABoy all drives are
SATA. On all systems file copies using small files up to 0 - 40GB are all
successful.
All systems are running the latest BIOS and we have seen the same behavior
on prior BIOS versions. All disk controller firware is updated to the latest
version and like the BIOSes the same behavior existed on earlier versions.
We have checked and updated hard disk firmware, where new versions are
available. Same issues as for controller firmware. On local Hard drives we
run Raid 1 or Raid 5 to get best performance or max capacity. Both Raid
modes exhibit the same behavior. I have tested on the HP's with no Raid at
all and the same results occurred.

I try not to do specialty O/S builds for our lab environment. I build a
straight default Windows O/S configurations, fully patch it with microsoft
Patches and burn in test the system, then go test for this problem. I do not
tweak system settings or apply registry hacks until I get baseline test
data. In all cases here for the file copy tests I have not tweaked the
system settings or registry at all. Our servers are set for background
performance for the system cache, although we tested with 'foreground' set
without success too. We've tried large and small pagefiles and have moved
pagefiles to seperate disk spindles to see if it made a difference.
I've tried all manner of file copy and file sync tools, but what it comes
down to that if the file being copied is written on the systems' storage
system (local or SAN), the system will collapse and file copying will fail
somewhere around 52 - 58GB being copied. Windows Server 2008 has given me my
best look into the problem and what appears to be happening is that the
system cache keeps expanding until all physical memory is used and the paged
pool keeps growing until it hits around 380MB and non paged hits about 82MB
(I think the latter is right). What I then see is the CPU goes flat line as
does the Total Disk byes written in Perfmon but the Physical memory usage
history in task manager suddenly starts ramping until it gets out around
70GB and then everything is done and either the system hangs (server2008) or
delayed write errors occur.

One place where I do not seem to see the problem is SAN Drive to SAN Drive
Copies on the EMC SAN. I always see this problem on the SATABOY SAN with
large files when copying large files to the SAN volumes regardless of Cache
Settings. I can backup the files to tape but due to their size its an
expensive option both in media cost and time to backup and restore the data,
my preferred option is to backup to removeable Hard Disk (External USB -
SATA), sure its slower but it offers operating efficiencies right now I
cannot get with Tape (if it worked). Some testing has centered on using
external drives, but most of the testing on my systems has been to copy or
move the files from one volume to another on the server. It doesn't matter
whether I turn caching off or on for external USB drives or local drives. I
have had very occasional success on the EMC SAN ensuring that windows O/S
disk caching is off. Success using this method has been spotty and limited
to servers with 32GB or more of RAM. One very telling test setup was to
populate the Server with 128GB RAM and run windows Server 2008 x64. In that
case almost all file copies were successful, although they became painfully
slow after about 60GB was copied and it took over 5 hours to copy the last
~35GB of a 95.8 GB file.

I tried using Backup Exec and MsBackup to backup the files to a hard disk
but it failed everytime, when I run the same backup to tape it is
successful.
This is leading me to think the problem is generated in the lower level file
system filter drivers. I've tested with and without AntiVirus software in
the mix and have likewise tested systems that are built raw with no patches
at all and see the same problems. I also tried splitting the file into
chunks and copying the pieces and while I can split the file, I cannot join
it again as the processes all seem to rely on creating a temp file and the
process of copying the large temp file always results in the delayed write
errors being generated. I've also tried zipping up the file to reduce its
size (database files compress really well) but that process likewise
requires a file copy of a large file, and at some point that fails. It
should go without saying I've tried using SQL Db Backup writing to disk
storage and it fails everytime, tape is successful. In fact it was this very
act that caused me to begin investigating the problem in the first place.

In days gone by there were loads of users seeing this problem on Win XP
copying much smaller files and there are some other people seeing this
problem today on Windows Server, Microsoft are very quiet on the subject for
windows server, I think in no small part because very few people are seeing
the problem and there is no demand to identify the problem or to fix it. I
cannot believe though I'm one of the first people to see the problem.
I'll quite happily accept its a configuration issue if someone can tell me
how to fix the problem! All attempt to tweak a system has not yielded any
success. What also sucks is that you typically have to wait ~30 mins to find
out that the problem will manifest.

I'm about ready to escalate this issue to Microsoft, I think I now have
enough test data to do so, but thought I would bounce this off others to see
if anyone else has a solution or guidance first.

Phil
Checkfree:


Posted by John Fullbright on May 24th, 2008


The data section of the event ID 50 contains a lot of useful information for
diagnosing the exact cause of the issue. Could you check the "words" radio
button and post the dump data? Also, what is the source of the ID 50? is
it mrxsmb or disk?




"Phil Lewis" <jplewis01@comcast.net> wrote in message
news:uVXDdzbvIHA.4876@TK2MSFTNGP02.phx.gbl...


Posted by Ace Fekay [MVP] on May 24th, 2008


In news:uVXDdzbvIHA.4876@TK2MSFTNGP02.phx.gbl,
Phil Lewis <jplewis01@comcast.net> typed:
Interesting dillema. I have not seen it before.

What are the Source names for the event IDs you posted?

Out of curiousity, I looked up EventID 50, but there are numerous Source
names, none of which their descriptions did I find to indicate a "Windows
Delayed Write" message, as you've described. Looking through different
possible error messages of "{Delayed Write Failed}," I found numerous
possiblities, but you would have to sort through them. One indicated a
problem wtih the MFT, another indicated issues with fragmentation causing
it, and one concerining clustering drivers conflicts and one more about
compatibility issues with the HBA the SAN is connected to.

See if you can weed through the following EventID links. Look up based on
the Source name. If you don't have a subscription and it indicates an MSKB,
prefix the KB number so it the URL reads
"htttp://support.microsoft.com/kb/######" (###### being the KB number).

http://eventid.net/display.asp?eventid=50&source=
http://eventid.net/display.asp?eventid=26&source=


--
Regards,
Ace

This posting is provided "AS-IS" with no warranties or guarantees and
confers no rights.

Ace Fekay, MCSE 2003 & 2000, MCSA 2003 & 2000, MCSE+I, MCT,
MVP Microsoft MVP - Directory Services
Microsoft Certified Trainer

For urgent issues, you may want to contact Microsoft PSS directly. Please
check http://support.microsoft.com for regional support phone numbers.

Infinite Diversities in Infinite Combinations



Posted by John Fullbright on May 24th, 2008


Being that they're at Windows 2003 SP2 or Windows 2008, my guess would be
CcDirtyPageThreshold is set too high. Let's see the details of the event ID
50. The event ID 26 is really immaterial, it's just the application popup
message (you got the dialog that says lost delayed write)., The evend ID 50
will contain the error code passed up the driver stack, as well as any SCSI
sense data. Between that and possibly a short perfmon run during a copy, we
should be able to sort this out. My guess is that we'll see half of RAM
cached before writing starts, then you'll either see c000009a (out of
resources) or a timeout due to slow disk once dirty pages are flushed. In
perfom, you'll see heavy paging once dirty pages start flushing, and this is
really the cause of the lack of server responsiveness.

The narrative

"Windows Server 2008 has given me my best look into the problem and
would be supportive of this guess.

John



"Ace Fekay [MVP]" <PleaseAskMe@SomeDomain.com> wrote in message
news:%23c90ULcvIHA.5620@TK2MSFTNGP04.phx.gbl...


Posted by Phil Lewis on May 24th, 2008


Hi John
Event 50 is being generated by Disk. I think that is being seen on all
servers, though I've seen one or two cases where mrxsmb was the source when
doing network copies. I can also confirm that at least 50% of RAM was indeed
cached, in most cases it was much higher. While we have seen c000009a (out
of resources), in almost all cases, disk timeouts occurred as a failure
point and yes indeed we experience very heavy paging when or just before
the system tips over. On Server 2008 we were seeing the dedicated pagefile
disk active solidly for over an hour before we finally gave up waiting for
the copy to quit and the system to shutdown.
I'll get the event viewer dumps later tonight and I can also get a Perfmon
Dump as well. Let me know what counters you would like to see included so I
get you exactly the necessary data. tonight, I can just load a Perfmon
template on the server and dump the output if you want to specify a bunch of
counters.

I have not played with CcDirtyPageThreshold yet, I was extremely tempted
last week, but have thus far resisted. We run SP2 on all our WinSvr2003
servers. and one article I read had a hotfix for the problem that applied
only to SP1. Microsoft Support confirmed the fix in the article was included
in SP2 and I've not yet added the DWord value to modify it.

Phil

..
"John Fullbright" <fjohn@donotspamnetappdotcom> wrote in message
news:uZygHicvIHA.5472@TK2MSFTNGP06.phx.gbl...


Posted by John Fullbright on May 26th, 2008


The fix is there with SP2, but you still need to set the registry key.

cache
copy reads/se
data flush pages/sec

memory
pages/sec
free system page table entries

physical disk
sec/read
sec/write
reads/sec
writes/sec



John Fullbright [Exchange MVP]




"Phil Lewis" <jplewis01@comcast.net> wrote in message
news:uxIrTZdvIHA.576@TK2MSFTNGP05.phx.gbl...


Posted by Phil Lewis on May 28th, 2008


Hi John I'm about to grab the counters to a CSV File or do you prefer
Binary?

What do you recommend in terms of sample interval? I typically use 5 Second
intervals for this kind of thing but will adjust to whatever you prefer.

I'm grabbing Physical disk counters for both _Total and the Target disk
[D:\] for the Copy.

The first set of counters will be without the reg key being added to see the
system in the raw state. I'll then add the key, what do you recommend in
terms of a value? the Server is a HP ML570 Quad Xeon Dual Core 3.33GHz with
16GB of Ram. Reading suggests starting at half of installed Ram which would
be 8192.

Phil


"John Fullbright" <fjohn@donotspamnetappdotcom> wrote in message
news:uHNkMtvvIHA.4772@TK2MSFTNGP03.phx.gbl...


Posted by Mat Young on May 28th, 2008


Avg Disk Sec Read and write would be handy. if you are getting Lost write
because your array is being overun beyond the spindle count, then this may
show up in a latency response spike beforehand.

It would also be good to match IO versus spindle count. To do this properly
you will need cache hit ratio from the arrays.

rgds

mat

"Phil Lewis" wrote:

Posted by Phil Lewis on May 28th, 2008


Well I'm getting some very interesting findiong that I don't yet know what
to make of.

First off It looks like the whole train of events ultimately leading up to
the delayed write failure begins about 2-4 mins into the copy process. The
File copy in Windows Explorer begins normally and the 88.6GByte copy shows
it is expecting to take around 24-26 mins. Watching a whole slew of counters
in Perfmon I can see the Cache Bytes Growing steadily and Disk Total Reads
per second running avg around 190. Somewhere around 2-4 mins into the copy
the time to complete estimate in windows Explorer suddenly climbs
dramatically topping out around 100Mins. At the exact same time in perfmon I
see a sudden drop in the Total Disk Reads / Sec. The level drops from about
190 AVG to about 32 and the cache bytes growth goes dead flat. Avg Disk
queue stays the same and Writes continue to occur at the same levels as
before. After several minutes the Disk reads go back up to their previous
levels for a minute or two then they drop again and shortly after that, the
Disk write counters tank again and within 10-15 seconds The Delayed Write
error occurs.

So far I cannot see what is causing the Disk Reads to suddenly tank to about
25% of the initial level. When the system, picks back up midstream there is
a sudden spike in the number of Lazy Write Flushes and lazy write pages
lasting about 1 or 2 seconds then they drop off to almost zero.

Throughout copy the Free System Page Table Entries is flat at 40209. When
the system picks up again mid-Stream, the Cache Bytes and System Cache
Resident Bytes suddenly ramp up and seems to flatten out at approx
360,000,000 Bytes. Once the system Tanks the Bytes stay up until the file
copy is aborted and after a few mins it drops back to about 125,000,000
Bytes.

John, I'll Email you the Perfmon trace from the first run earlier later
tonight.



"John Fullbright" <fjohn@donotspamnetappdotcom> wrote in message
news:uHNkMtvvIHA.4772@TK2MSFTNGP03.phx.gbl...

Posted by Kenny Speer on May 28th, 2008


Please take these comments with a grain of salt. It's typically pretty
difficult to troubleshoot these issues via newsgroup.

Phil Lewis wrote:
[Kenny] This is most likely being caused by two things. First the NTFS
Cache writes is where your low time comes from. The AVG 190 IOPs to
your array are most likely from a write-back cache in the array.

Somewhere around 2-4 mins into the copy
[Kenny] You just filled your cache for the filesystem.

At the exact same time in perfmon I
[Kenny] Array cache is most likely filled at this point, so your
throughput to the array just dropped since at this point you are running
as fast as the array can write to disk instead of how fast it can write
to cache.

Avg Disk
[Kenny] This is the cache filling and flushing then filling and flushing.

and shortly after that, the
[Kenny] Hmm, not sure about this. It is quite possible that the array
simply dropped the IO on the floor. What do the event logs show up to
this point? Are there any logs you can enable on the target?

Posted by John Fullbright on May 29th, 2008


Note that all the target storage listed is SATA disk. RAID 1 has a write
penalty of 2 and RAID 5 has a write penalty of 4, compounding the issue.
Eveng copying from one RAID array to another, your read performance will be
greater than your write performance. This is totally consistent with the
CcDirtyPageThreshold set too high scenario. Once host cache fills to the
point where it starts flushing, you quickly swamp any cache on the storage
and the high page faults begin. If you lower the threshold, the idea is that
you wil stay within the fill/flush range and not swamp the disk.


"Kenny Speer" <kenny.speer@gmail.com> wrote in message
news:usoA%23URwIHA.524@TK2MSFTNGP05.phx.gbl...


Posted by Phil Lewis on May 29th, 2008


Yep I believe this is what I'm looking at right now But I'm in need of
guidance on what value to set for the registry entry:
SystemCacheDirtyPageThreshold at least to start with. I've tried several
very large values and two smaller ones 896 and 256 and neither corrected the
issue but did produce subtlely differing behaviors in the counters. Very
Small values get the dropoff in disk reads / Sec to occur in just a few secs
of starting which is fine and About a minute later I See a spike in the lazy
writes. This is preceeded by a jump in the Cache Bytes and System Cache
Resident Bytes. What else is interesting and here is where the problems come
from is that the cache grows each time just before lazy write occurs UNTIL
System Cache Resident Bytes hits right around 522,000,000 Bytes then the
frequency inteval of lazy write flushes drop from about 30 - 40 secs to
about 3 or more mins and cache growth goes flat line. The writes are
continuing but clearly the system seems to be getting overwhelmed. it should
also be noted that lazy writes and flushes are occurring still but the
frequent flushes stop once the sytem cache get filled.
Something else interesting is that the Cache Bytes is continuing to grow
slowly while System Cache Resident Bytes is essentially flat it look like
system cache include the full system working set in its size and the working
set appears to grow over time. I'm betting that once cache bytes get closer
to 960-1024 MB the system will tip over.

I take it there is no way to adjust the forced writes interval of the lazy
writes, is that true?

I should also point out that it does not matter what disk type or raid mode
is used. I'm easily able to produce this error on any Windows Server 2000
2003 2008 running any combination of disks SCSI, SAS, SATA PATA,
ExtUSB-SATA.All I need is a large file >52GB in size, which I have a good
number of.

Phil





"John Fullbright" <fjohn@donotspamnetappdotcom> wrote in message
news:%23LMbM8SwIHA.4376@TK2MSFTNGP06.phx.gbl...


Posted by Dilip Naik on July 1st, 2008


Phil, can you provide an update to this problem? Have you found a solution?

I am highly interested in the solution for personal reasons and am willing
to spend some cycles tracking one down if not already found

Dilip
www.msftmvp.com

"Phil Lewis" <jplewis01@comcast.net> wrote in message
news:e$ZdTGZwIHA.1980@TK2MSFTNGP02.phx.gbl...

Posted by Dilip Naik on July 1st, 2008


Phil,

One more suggestion

Reading this mail thread clearly indicates that both read and write caching
are suspected. Why not try getting rid of Large Cache and rerun the
experiment?

Contact me off line - I have a filter driver that I would be willing to
quickly modify to suit your needs - the driver would ensure certain files
bypass the System Cache. I am not looking for any $$ to do this.

Dilip
www.msftmvp.com

"Dilip Naik" <DilipCNaik@hotmail.com> wrote in message
news:O4h0hfz2IHA.1200@TK2MSFTNGP04.phx.gbl...


Similar Posts