Help: Single 512-byte write to file taking 5-10 minutes

Help: Single 512-byte write to file taking 5-10 minutes

Post by noon » Thu, 29 Jun 2006 06:28:11


've got a really strange performance problem. Occasionally, Windows takes
between 5 and 10 minutes (yes, _minutes_) to complete a write operation.
FileMon shows that Windows is reading sequentially through the entire file
during the write interval. Here are the details:

I am running with Windows XP Professional with SP2 and all other updates
installed. My program is written in C++ using Visual Studio 6.0.

The problem is intermittent and appears to be related to the intensity of
the I/O to the various files.

I am developing a multi-threaded application that accesses about 120 files;
all of the files are open.

While attempting to debug this problem, I put critical sections around all
Windows I/O API calls, so only one thread is doing I/O at a time.

The 120 files range in size from about 10 Kb to 2 GB. They are all on the
same disk which is formatted with NTFS.

Access to the files is random, but often there is a sequence of consecutive
operations. All accesses are on 512-byte boundaries. Most reads and writes
are exactly 512 bytes long, but some are smaller. No reads or writes are
longer than 512 bytes.

Here is a history log generated by my program showing the operations and the
elapsed time for each operation in parentheses. The first number after the
command is the 512-byte block position in the file.

03:00:35 (0.000) -- ReadBlock - Seek, 49817, 0
03:00:35 (0.000) -- ReadBlock - Read, 49817, 512
03:00:36 (0.000) -- ReadBlock - Seek, 104322, 0
03:00:36 (0.031) -- ReadBlock - Read, 104322, 512
03:00:36 (0.000) -- ReadBlock - Seek, 104323, 0
03:00:36 (0.000) -- ReadBlock - Read, 104323, 512
03:00:36 (0.000) -- ReadBlock - Seek, 104324, 0
03:00:36 (0.000) -- ReadBlock - Read, 104324, 512
03:00:36 (0.000) -- ReadBlock - Seek, 190476, 0
03:00:36 (0.016) -- ReadBlock - Read, 190476, 512
03:00:36 (0.000) -- WriteBlock - Seek, 507043, 0
03:00:36 (339.922) -- WriteBlock - Write, 507043, 512

Note that everything is running smoothly until a write that takes 339.922
seconds.

The problem seems to occur only on writes that follow a number of reads. I
have never seen a read hang.

Using the ileMonprogram to watch what's going on, I see during the write
internally Windows is reading sequentially through the entire data file (up
to 2 GB); the reads are advancing by 65 Kb per read. This sequential access
is being performed by the Windows I/O system at a deeper level than my
program. The 512-byte write operation I issued does not complete and return
to my program until the sequential scan is completed (which may take several
minutes).

During the time that the write is being executed by Windows, my program is
hung, and I cannot stop the execution using breakpoints. If I kill the
program using the Windows task manager, the disk activity continues until
the sequential read through the file is completed.

All I/O is performed using Windows API services. Here is the form of the
file open:

HANDLE m_handle;
m_handle = ::CreateFile(filename,GENERIC_READ|GENERIC_WRITE,
FILE_SHARE_WRITE|FILE_SHARE_READ,0,flags,
FILE_ATTRIBUTE_NORMAL|FILE_FLAG_RANDOM_ACCESS,0);

Here is the form of the seek:

LARGE_INTEGER distance;
/* Convert block number to 64-bit byte number */
distance.QuadPart = (__int64)offset * (__int64)IOBLOCKSIZE;
::SetFilePointer(m_handle,distance.LowPart,&distance.HighPart,origin);

Here is the f