一个简单而又不影响运行的日志函数
2011-09-09 17:32
459 查看
I/O操作比较耗时,在硬盘频繁读写时尤其耗时,比如杀毒软件扫描,磁盘碎片整理,索引服务之类的。如果在运行效率有要求的环境下有大量I/O的话就不得不考虑如何让I/O不影响运行。
I/O操作比如说日志,可以输出到DbgView,也可以输出到文件。当有bug时,可以告诉我们问题出在哪儿。输出到DbgView与输出到文件各有利弊。输出到DbgView,好处是不影响程序运行,坏处是需要开DbgView(有时客户不方便开),要考虑DbgView内存开销(这样的话,无法看到时间靠前的日志),不能动DbgView(否则会堵塞程序,拖动进度条,保存文件,清除log之类的操作)。输出到文件,好处是要求少,坏处是有大量I/O操作,必须合理的设计保证不影响程序运行。
最先想到也是最容易想到的解决方案是,将Log丢到缓冲,创建一个子线程专门将这些Log输出到文件。我问自己能不能在现有的文件日志基础上做最少的改动以实现目的。
现有的日志函数
我想到了采用异步I/O的方式,或许能解决这个问题。按照Windows核心编程的说法
Consider a thread that issues an asynchronous I/O request to a device. This I/O request is passed to a device driver,which assumes the responsibility of actually performing the I/O.While the device driver waits for the device to respond, the application's
thread is not suspended as it waits for the I/O request to complete. Instead, this thread continues executing and performs other usefull tasks.
但是采用了异步I/O之后,实际测试过程中,CreateFile有时候需要16ms,而WriteFile经常超过2ms,甚至超过100ms。因此我考虑文件句柄放到全局,一开始的时候创建,退出程序前销毁,同时将日志先丢到缓冲,每隔1s再一次性写到文件中。
改进后的日志函数
I/O操作比如说日志,可以输出到DbgView,也可以输出到文件。当有bug时,可以告诉我们问题出在哪儿。输出到DbgView与输出到文件各有利弊。输出到DbgView,好处是不影响程序运行,坏处是需要开DbgView(有时客户不方便开),要考虑DbgView内存开销(这样的话,无法看到时间靠前的日志),不能动DbgView(否则会堵塞程序,拖动进度条,保存文件,清除log之类的操作)。输出到文件,好处是要求少,坏处是有大量I/O操作,必须合理的设计保证不影响程序运行。
最先想到也是最容易想到的解决方案是,将Log丢到缓冲,创建一个子线程专门将这些Log输出到文件。我问自己能不能在现有的文件日志基础上做最少的改动以实现目的。
现有的日志函数
static unsigned short EnableLog = 1; //允许写日志 static unsigned short EnableDbgView = 0; //允许写到debug view TCHAR g_szFilePath[MAX_PATH]; int MyIO(LPCSTR fmt, ...) { va_list ap; char MsgBuf[512] = {0}; static char szDate[50] = {0}; static char szTime[50] = {0}; clock_t tStart = clock(); va_start( ap,fmt ); vsprintf( MsgBuf,fmt,ap ); va_end( ap ); if(MsgBuf[strlen(MsgBuf)-1] == '\n') MsgBuf[strlen(MsgBuf)-1] = '\0'; if(EnableLog) { SYSTEMTIME st; char szLog[1024] = {0} GetLocalTime(&st); // 取当前系统时间 sprintf_s(szTime, sizeof(szTime), "%02d:%02d:%02d.%03d", \ st.wHour, st.wMinute, st.wSecond, st.wMilliseconds); sprintf_s(szDate, sizeof(szDate), "%04d%02d%02d", st.wYear, st.wMonth, st.wDay); sprintf_s(); int nBufLen = strlen(szBufferPerSec); sprintf(szLog, "%s -> %s\r\n", szTime, MsgBuf); TCHAR szFileName[MAX_PATH]; sprintf_s(szFileName, sizeof(szFileName), "%sMyIODemo_%s.txt", \ g_szFilePath, szDate); HANDLE hLogFile = CreateFile(szFileName, GENERIC_WRITE, FILE_SHARE_READ,//|FILE_SHARE_DELETE, NULL, OPEN_ALWAYS,//if not exist,creat new //CREATE_ALWAYS, FILE_ATTRIBUTE_NORMAL, 0); if(hLogFile == INVALID_HANDLE_VALUE) { TRACE("Error!!!can't open %s to write", szFileName); return -1; } SetFilePointer(hLogFile , NULL, NULL, FILE_END); BOOL bRet = WriteFile(hLogFile , szLog, strlen(szLog), NULL, NULL); if(!bRet) { TRACE( "Error!Could not write to file (error %d)\n", GetLastError()); } if(clock()-tStart>2) { OutputDebugString("Error!log time-consumingly to file"); } if(hLogFile ) { CloseHandle(hLogFile ); hLogFile = NULL; } } if(EnableDbgView) OutputDebugString(MsgBuf); return 0; }
我想到了采用异步I/O的方式,或许能解决这个问题。按照Windows核心编程的说法
Consider a thread that issues an asynchronous I/O request to a device. This I/O request is passed to a device driver,which assumes the responsibility of actually performing the I/O.While the device driver waits for the device to respond, the application's
thread is not suspended as it waits for the I/O request to complete. Instead, this thread continues executing and performs other usefull tasks.
但是采用了异步I/O之后,实际测试过程中,CreateFile有时候需要16ms,而WriteFile经常超过2ms,甚至超过100ms。因此我考虑文件句柄放到全局,一开始的时候创建,退出程序前销毁,同时将日志先丢到缓冲,每隔1s再一次性写到文件中。
改进后的日志函数
static unsigned short EnableLog = 1; //允许写日志 static unsigned short EnableDbgView = 0; //允许写到debug view static HANDLE g_hLogFile = NULL; static OVERLAPPED g_laped = {0}; TCHAR g_szFilePath[MAX_PATH]; int MyIO(LPCSTR fmt, ...) { va_list ap; SYSTEMTIME _SysTime; char MsgBuf[512] = {0}; bool bFlush = false; static clock_t tLastLog = clock()-1; static clock_t tLast = clock()-1; clock_t tStart = clock(); char szToday[50] = {0}; static char szDate[50] = {0}; static char szTime[50] = {0}; static char szBufferPerSec[1024*1024] = {0}; static int nCurFileSize = 1024*1024; va_start( ap,fmt ); vsprintf( MsgBuf,fmt,ap ); va_end( ap ); if(MsgBuf[strlen(MsgBuf)-1] == '\n') MsgBuf[strlen(MsgBuf)-1] = '\0'; if(EnableLog) { SYSTEMTIME st; if(tStart>tLast) { GetLocalTime(&st); // 取当前系统时间 sprintf_s(szTime, sizeof(szTime), "%02d:%02d:%02d.%03d", \ st.wHour, st.wMinute, st.wSecond, st.wMilliseconds); if(tStart-tLastLog>1000) { bFlush = true; tLastLog = tStart; } tLast = tStart; } sprintf_s(szToday, sizeof(szToday), "%04d%02d%02d", st.wYear, st.wMonth, st.wDay); if(strcmp(szToday, szDate)) { if(g_hLogFile!=NULL) { CloseHandle(g_hLogFile); g_hLogFile = NULL; } strcpy(szDate, szToday); } int nBufLen = strlen(szBufferPerSec); sprintf(szBufferPerSec+strlen(szBufferPerSec)/*, sizeof(szBufferPerSec)*/, "%s -> %s\r\n", szTime, MsgBuf); if(bFlush) { if(g_hLogFile == NULL) { TCHAR szFileName[MAX_PATH]; sprintf_s(szFileName, sizeof(szFileName), "%sMyIODemo_%s.txt", \ g_szFilePath, szDate); g_hLogFile = CreateFile(szFileName, GENERIC_WRITE, FILE_SHARE_READ,//|FILE_SHARE_DELETE, NULL, OPEN_ALWAYS,//if not exist,creat new //CREATE_ALWAYS, FILE_FLAG_OVERLAPPED/*FILE_ATTRIBUTE_NORMAL*/, 0); if(g_hLogFile == INVALID_HANDLE_VALUE) { TRACE("Error!!!can't open %s to write", szFileName); return -1; } SetFilePointer(g_hLogFile, nCurFileSize, NULL, FILE_BEGIN); SetEndOfFile(g_hLogFile); } //!sld! 2011.9.13 快满的时候,文件尺寸翻倍。如果不加这个的话,一旦写入超过文件尺寸,最后文件Log将没有内容,全是NULL。 if((int)(nCurFileSize - g_laped.Offset - strlen(szBufferPerSec))<=0) { nCurFileSize = nCurFileSize*2; SetFilePointer(g_hLogFile, nCurFileSize, NULL, FILE_BEGIN); SetEndOfFile(g_hLogFile); } BOOL bRet = WriteFile(g_hLogFile, szBufferPerSec, strlen(szBufferPerSec), NULL, &g_laped); if(!bRet) { DWORD dwErrNo = GetLastError(); if(dwErrNo!=ERROR_IO_PENDING) { char szErr[1024]; sprintf_s(szErr, sizeof(szErr), "Error!Could not write to file (error %d)\n", dwErrNo); OutputDebugString(szErr); } } if(clock()-tStart>2) { OutputDebugString("Error!log time-consumingly to file"); } g_laped.Offset+=strlen(szBufferPerSec); memset(szBufferPerSec, 0, sizeof(szBufferPerSec)); } } if(EnableDbgView) OutputDebugString(MsgBuf); return 0; }现在经过测试WriteFile开销还是像之前一样,但是已经可以容忍了。没有在多线程环境下测试,但是料想应该能正常工作。
相关文章推荐
- 一个简单的装饰器算出函数运行时间
- 一个简单用C语言实现的日志函数
- 一个简单的日志函数C++
- 一个简单用C语言实现的日志函数
- 一个简单函数的是如何运行的
- Golang记录、计算函数执行耗时、运行时间的一个简单方法
- 使用Node.js + MongoDB实现一个简单的日志分析系统
- 一个简单、漂亮、功能强大的Android日志程序:logger
- java拾遗4----一个简单java程序的运行全过程
- 一个简单、漂亮、功能强大的Android日志程序:logger
- Linus---一个简单ls-l函数
- 一个简单java小程序打包成EXE运行文件
- 简单操作权限就一个函数足够了,甚至5-6个表足够可以了,没必要搞那么复杂,也没必要瞎搞误人子弟啊
- C语言10的n次方pow函数不好用,自己写一个简单的
- 非常简单的一个函数 竟然一直没有使用 find()
- 一个简单的jQuery回调函数例子
- Erlang笔记(02) - 编写并运行一个简单的 Erlang 文件
- 一个简单的关于函数指针的实例
- 运行一个最简单的 electron 项目
- 一个简单的PHP生成缩略图函数