A simple log function that does not affect running

I/O operations are time-consuming, especially when hard disks are frequently read/written, such as anti-virus software scanning, disk fragmentation, and Indexing Services. If there is a large number of I/O in an environment with high operation efficiency, you have to consider how to make I/O not affect the operation.

I/O operations such as logs can be output to dbgview or a file. When there is a bug, you can tell us where the problem is. The advantages and disadvantages of outputting data to dbgview are as follows. The advantage of outputting data to dbgview is that it does not affect the running of the program. The disadvantage is that dbgview needs to be enabled (sometimes it is not convenient for the customer to open it), and dbgview memory overhead should be taken into account (in this case, the logs at the top of ), dbgview is not supported (otherwise, the program will be blocked, and operations such as dragging progress bars, saving files, and clearing logs will be performed ). The advantage of output to a file is that there are few requirements, and the disadvantage is that there are a large number of I/O operations. It must be properly designed to ensure that the program running is not affected.

The first and most easy-to-think solution is to throw logs to the buffer and create a subthread to output these logs to the file. I asked myself if I could make the least changes on the basis of the existing file logs for the purpose.

Existing log Functions

Static unsigned short enablelog = 1; // allow the write log to static unsigned short enabledbgview = 0; // allow the write to debug viewtchar g_szfilepath [max_path]; int myio (lpcstr FMT ,...) {va_list AP; char msgbuf [512] = {0}; static charszdate [50] = {0}; static charsztime [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 (EN Ablelog) {systemtime st; char szlog [1024] = {0} getlocaltime (& St); // obtain the current system time 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 (SZ Filename, sizeof (szfilename), "updated", \ g_szfilepath, szdate); handle hlogfile = createfile (szfilename, generic_write, file_1__read, // | file_1__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! Cocould 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 thought about adopting asynchronous I/O, which may solve this problem. According to Windows core programming

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 swimming the I/O. while the device driver waits for the device to respond, the application's
Thread is not suincluded as it waits for the I/O Request to complete. Instead, this thread continues executing and performs other usefull tasks.

However, after asynchronous I/O is used, in actual testing, createfile sometimes takes 16 ms, while writefile often exceeds 2 ms, or even more than 100 ms. Therefore, I want to put the file handle to the global location. I created it at the beginning and destroyed it before exiting the program. At the same time, I threw the log to the buffer and wrote it to the file once every 1 s.

Improved LOG Functions

Static unsigned short enablelog = 1; // allow to write logs static unsigned short enabledbgview = 0; // allow to write logs to debug viewstatic handle g_hlogfile = NULL; static overlapped g_laped = {0 }; tchar g_szfilepath [max_path]; int myio (lpcstr FMT ,...) {va_list AP; systemtime _ javasime; 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 charszdate [50] = {0}; static charsztime [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); // obtain the current system time 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 (second) /*, sizeof (szbufferpersec) */, "% s-> % s \ r \ n", sztime, msgbuf); If (bflush) {If (g_hlogfile = NULL) {tchar szfilename [max_path]; sprintf_s (szfilename, sizeof (szfilename), "inclusmyiodemo_%s.txt", \ g_szfilepath, szdate); g_hlogfile = createfile (szfilename, Generic_write, file_share_read, // | file_assist_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! When 2011.9.13 is full, the file size doubles. If this is not added, once the size of the file is exceeded, the file log will have no content, all of which are 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! Cocould 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 ;}

Now the writefile overhead is tested as before, but can be tolerated. It is not tested in a multi-threaded environment, but should work properly.