Вот мое решение, которое я протестировал, и результаты хорошие:
LARGE_INTEGER liFreq, liNow;
SYSTEMTIME sstNow;
char szMsg[768];
long lngMicro;
/*Get high performance frequency and counter*/
QueryPerformanceFrequency(&liFreq);
QueryPerformanceCounter(&liNow);
/*Work out elapsed microseconds using frequency*/
liNow.QuadPart *= 1000000;
liNow.QuadPart /= liFreq.QuadPart;
/*Mask out everything >= 1 second */
lngMicro = liNow.QuadPart % 1000000;
/*Get the system date and time*/
GetLocalTime(&sstNow);
/*Build up formatted debug string including sequence number, line number
*date and time stamp including microseconds and message detail*/
sprintf_s(szMsg, sizeof(szMsg)
,"%4d-%02d-%02d %02d:%02d:%02d.%06ld DBG:%-24sL%05uSQ%05uET%16.6f%s%s\n"
,sstNow.wYear, sstNow.wMonth, sstNow.wDay
,sstNow.wHour, sstNow.wMinute, sstNow.wSecond
,lngMicro, cpszClipped, uintLineNo
,suintDbgSeqNo, dblElapsed, sszIndents, cpszFormat);
Это не вся функция, но, надеюсь, дает достаточно информации, чтобы кто-нибудь мог увидеть, что происходит и как это работаетВот фрагмент файла журнала, созданного с использованием этой техники:
2018-05-16 08:17:52.334189 DBG:FsLonSource.cpp L01079SQ00011ET 5.334189 CFsLonSource::SubmitCommand(AddressType:Local NI, Mode:0, Selector:0)
2018-05-16 08:17:52.334449 DBG:NodetalkLONInterface.c L01862SQ00012ET 5.334449 AdapterSetAddress(DomainId:, SubnetId:1, NodeId:1)
2018-05-16 08:17:52.334807 DBG:NodetalkLONInterface.c L01522SQ00013ET 5.334807 AdapterSetAddressInternal(DomainId:, SubnetId:1, NodeId:1)
2018-05-16 08:17:52.335413 DBG:NodetalkLONInterface.c L01021SQ00014ET 5.335413 NodeSetAddress(ServiceType: ACKD): ok
2018-05-16 08:17:52.335603 DBG:NodetalkLONInterface.c L01055SQ00015ET 5.335603 NodeSetModeState()
2018-05-16 08:17:52.335783 DBG:NodetalkLONInterface.c L01064SQ00016ET 5.335783 ServiceType: UNACKD
2018-05-16 08:17:52.335966 DBG:NodetalkLONInterface.c L01065SQ00017ET 5.335966 NewMode: ?
2018-05-16 08:17:52.336124 DBG:NodetalkLONInterface.c L01071SQ00018ET 5.336124 NewState: Configured, Online
2018-05-16 08:17:52.339081 DBG:FsLonDispatch.cpp L00342SQ00019ET 5.339081 CFsLonDispatch::ExecRequest(): S_OK
2018-05-16 08:17:52.433098 DBG:FsLonDispatch.cpp L00181SQ00020ET 5.433098 CFsLonDispatch::ExecRequest(request:"<UpdateRest xmln", lTimeout:0, destination:"", correlationId:"")
2018-05-16 08:17:52.436138 DBG:FsLonDispatch.cpp L00250SQ00021ET 5.436138 strCCommand: UpdateRest
2018-05-16 08:17:52.436431 DBG:FsLonDispatch.cpp L00342SQ00022ET 5.436431 CFsLonDispatch::ExecRequest(): S_OK
2018-05-16 08:17:52.437184 DBG:FsLonDispatch.cpp L00181SQ00023ET 5.437184 CFsLonDispatch::ExecRequest(request:"<UpdateRest xmln", lTimeout:0, destination:"", correlationId:"")
2018-05-16 08:17:52.439981 DBG:FsLonDispatch.cpp L00250SQ00024ET 5.439981 strCCommand: UpdateRest
2018-05-16 08:17:52.440331 DBG:FsLonDispatch.cpp L00342SQ00025ET 5.440331 CFsLonDispatch::ExecRequest(): S_OK
2018-05-16 08:17:52.440705 DBG:FsLonDispatch.cpp L00181SQ00026ET 5.440705 CFsLonDispatch::ExecRequest(request:"<UpdateRest xmln", lTimeout:0, destination:"", correlationId:"")
2018-05-16 08:17:52.443586 DBG:FsLonDispatch.cpp L00250SQ00027ET 5.443586 strCCommand: UpdateRest
2018-05-16 08:17:52.443792 DBG:FsLonDispatch.cpp L00342SQ00028ET 5.443792 CFsLonDispatch::ExecRequest(): S_OK
2018-05-16 08:17:52.951870 DBG:NodetalkLONInterface.c L01108SQ00029ET 5.951870 ServiceType: REQUEST
2018-05-16 08:17:52.955944 DBG:NodetalkLONInterface.c L01152SQ00030ET 5.955944 NodeSetModeState(): ok
2018-05-16 08:17:52.956289 DBG:NodetalkLONInterface.c L01555SQ00031ET 5.956289 AdapterSetAddressInternal(): ok
2018-05-16 08:17:52.956655 DBG:NodetalkLONInterface.c L01597SQ00032ET 5.956655 AdapterSetRcvTimer(ServiceType: REQUEST, AddressType: LOCAL)
2018-05-16 08:17:52.966897 DBG:NodetalkLONInterface.c L01625SQ00033ET 5.966897 AdapterSetRcvTimer(): ok
2018-05-16 08:17:52.967216 DBG:NodetalkLONInterface.c L01878SQ00034ET 5.967216 AdapterSetAddress(): ok
2018-05-16 08:17:52.967531 DBG:FsLonSource.cpp L01174SQ00035ET 5.967531 CFsLonSource::SubmitCommand(): ok