Slow ifstream close when accessing network files
Summary:
I have a case where calling close() on an ifstream takes ~1 second if I am
accessing the file across the network. The problem does not appear if I
access the files locally.
Details:
The code in question opens an ifstream, calls seekg() with a non zero value,
reads at least 29185 bytes, then calls close on the ifstream. The close takes
~1 second to finish.
The ifstream must be opened using ios::binary.
The problem does not occur between all of my test boxes. It does not occur
if the machine running the test is running Vista, or 2003 Server. It occurs
on most (4 of 5) XP SP2 machines.
If I covert the ifstream pointer to a FILE* the problem does not occur (see
code below).
29185 = (512*57) + 1. Is this significant?
Ping times between the two machines are low (<1 ms).
Code:
// This program is intended to time the accessing of a file.
// Specifically, it reveals that ifstream::close() can take
// a very long time (~1 second) when performed against a file
// located on a network resource.
// See comments labeled "NOTE" for more details.
#include <iostream>
#include <fstream>
#include <time.h>
#include <windows.h>
#include <process.h>
using namespace std;
int COUNT = 0;
clock_t open_time = 0;
clock_t read_time = 0;
clock_t close_time = 0;
clock_t test_time = 0;
clock_t total_time = 0;
const char *TEST_FILE_NAME = NULL;
#define BUFFER_SIZE 29185
unsigned char BUFFER[BUFFER_SIZE];
unsigned int threadHandle = 0;
uintptr_t tHandle = 0;
HANDLE semaphore;
// ONLY "SAFE" FOR WIN32!!!!!
#define IOS_TO_PTR(ifs) ((FILE *)(*((unsigned int *)(((char *)ifs) + 84))))
// This routine tests (and records the time of) accessing the test file.
// It uses STL commands.
void TestFileAccess(void) {
clock_t s_time, st_time;
ifstream *ifs;
st_time = clock();
s_time = clock();
ifs = new ifstream;
// NOTE: Removing ios::binary from this call will result
// in much shorter close times for network files.
ifs->open(TEST_FILE_NAME, ios::in | ios::binary);
//FILE *fptr = IOS_TO_PTR(ifs);
if (!ifs->is_open()) {
cout<<"ERROR: Unable to open "<<TEST_FILE_NAME<<endl;
delete ifs;
return;
}
open_time += clock() - s_time;
s_time = clock();
// NOTE: If we do not perform this seek before
// doing our big read, close will be fast.
ifs->seekg(1, ios::beg);
int s = ifs->tellg();
//fseek(fptr, 1, SEEK_SET);
//int s = ftell(fptr);
// NOTE: This read must be at least 29185. If it is less,
// close will be fast.
ifs->read((char *)BUFFER, BUFFER_SIZE);
int e = ifs->tellg();
// NOTE: If we convert ifs to fptr (see the call after open),
// and use this fread instead of ifs-read, close will be fast.
//fread(BUFFER, 1, BUFFER_SIZE, fptr);
//int e = ftell(fptr);
if (e - s != BUFFER_SIZE) {
cout<<"ERROR: Unable to read from "<<TEST_FILE_NAME<<endl;
return;
}
read_time = clock() - s_time;
s_time = clock();
ifs->close();
delete ifs;
//fclose(fptr);
close_time += clock() - s_time;
test_time += clock() - st_time;
}
// This routine tests (and records the time of) accessing the test file.
// It uses FILE * commands.
void TestFileAccess2(void) {
clock_t s_time, st_time;
FILE *ifs;
st_time = clock();
s_time = clock();
ifs = fopen(TEST_FILE_NAME, "rb");
if (!ifs) {
cout<<"ERROR: Unable to open "<<TEST_FILE_NAME<<endl;
return;
}
open_time += clock() - s_time;
s_time = clock();
fread(BUFFER, 1, 2, ifs);
fseek(ifs, 2, SEEK_SET);
int s = ftell(ifs);
fread(BUFFER, 1, BUFFER_SIZE, ifs);
int e = ftell(ifs);
if (e - s != BUFFER_SIZE) {
cout<<"ERROR: Unable to read from "<<TEST_FILE_NAME<<endl;
return;
}
read_time = clock() - s_time;
s_time = clock();
fclose(ifs);
close_time += clock() - s_time;
test_time += clock() - st_time;
}
// This routine tests (and records the time of) accessing the test file.
// It uses Windows IO calls.
void TestFileAccess3(void) {
clock_t s_time, st_time;
st_time = clock();
s_time = clock();
HANDLE hFile;
hFile = CreateFileA(TEST_FILE_NAME, // file to open
GENERIC_READ, // open for reading
FILE_SHARE_READ, // share for reading
NULL, // default security
OPEN_EXISTING, // existing file only
FILE_ATTRIBUTE_NORMAL, // normal file
NULL); // no attr. template
open_time += clock() - s_time;
s_time = clock();
// Try to move hFile file pointer some distance
DWORD dwPtr = SetFilePointer(hFile, 50000, NULL, FILE_BEGIN);
if (dwPtr == INVALID_SET_FILE_POINTER) {
cout<<"ERROR: Unable to open "<<TEST_FILE_NAME<<endl;
return;
}
DWORD nBytesRead = 0;
BOOL lResult = ReadFile(hFile,
(void*)&BUFFER,
4,
&nBytesRead,
NULL);
if (lResult == FALSE || nBytesRead != 4) {
cout<<"ERROR: Unable to read from "<<TEST_FILE_NAME<<endl;
return;
}
dwPtr = SetFilePointer(hFile, 0, NULL, FILE_BEGIN);
if (dwPtr == INVALID_SET_FILE_POINTER) {
cout<<"ERROR: Unable to set file pointer"<<endl;
return;
}
nBytesRead = 0;
lResult = ReadFile(hFile,
(void*)&BUFFER,
BUFFER_SIZE,
&nBytesRead,
NULL);
if (lResult == FALSE || BUFFER_SIZE != nBytesRead) {
cout<<"ERROR: Unable to read from "<<TEST_FILE_NAME<<endl;
return;
}
read_time = clock() - s_time;
s_time = clock();
lResult = CloseHandle(hFile);
close_time += clock() - s_time;
test_time += clock() - st_time;
}
void Test(void) {
clock_t st_time;
st_time = clock();
for (COUNT = 0; COUNT < 10; ++COUNT) {
TestFileAccess();
}
total_time += clock() - st_time;
}
// Tried testing w/ a separate thread. No change occurred.
unsigned int __stdcall ThreadTestRun(void *args) {
Test();
ReleaseSemaphore(semaphore, 1, NULL);
_endthread();
return 0;
}
void ThreadTest(void) {
semaphore = CreateSemaphore(NULL, 0, 65535, NULL);
tHandle = _beginthreadex(NULL, 0, ThreadTestRun,
NULL, 0, &threadHandle);
WaitForSingleObject(semaphore, INFINITE);
CloseHandle((void *)tHandle);
}
int main(int argc, const char **argv) {
if (argc < 2) {
cout<<"USE: "<<argv[0]<<" [test file]"<<endl;
return 1;
}
TEST_FILE_NAME = argv[1];
Test();
cout<<"Open Time: "<<(double)open_time / CLOCKS_PER_SEC<<endl;
cout<<"Read Time: "<<(double)read_time / CLOCKS_PER_SEC<<endl;
cout<<"Close Time: "<<(double)close_time / CLOCKS_PER_SEC<<endl;
cout<<"Test Time: "<<(double)test_time / CLOCKS_PER_SEC<<endl;
cout<<"Total Time: "<<(double)total_time / CLOCKS_PER_SEC<<endl;
return 1;
}