BorlandTalk.com

Alex Liu · Guest

Hi,

I am writing a multi-threaded time-critical application in which every
thread will write some logs to a log file. I defined a global function to
write logs in this way:

void __fastcall TGlobal::WriteLog(AnsiString msg)
{
CriticalSection->Enter();
try
{
mylogfile->Write(FormatDateTime("hh:nn:ss.zzz", Now()), msg);
}
__finally
{
CriticalSection->Leave();
}
}

And generally my threads work in this way:

while(!Terminated)
{
MyGlobal->WriteLog("thread start job");
dosomefcn();

MyGlobal->WriteLog("thread finish job");
Sleep(1);
}

where MyGlobal is passed as a reference, inited globally.

Here is the strange part (well, I feel it strange). The log shows time like
this:
14:37:01.984 thread_A start job
14:37:01.984 thread_A finish job
14:37:01.984 thread_B start job
14:37:01.984 thread_B finish job
14:37:01.984 thread_C start job
14:37:01.984 thread_C finish job
14:37:02.312 thread_A start job
14:37:02.312 thread_A finish job
14:37:02.312 thread_A start job
14:37:02.312 thread_A finish job
14:37:02.312 thread_B start job
14:37:02.312 thread_B finish job
14:37:02.312 thread_B start job
14:37:02.312 thread_B finish job
14:37:02.328 thread_C start job
14:37:02.328 thread_C finish job
14:37:02.343 thread_A start job
14:37:02.343 thread_A finish job
14:37:02.343 thread_A start job
14:37:02.343 thread_A finish job
14:37:02.343 thread_B start job
14:37:02.343 thread_B finish job
14:37:02.343 thread_B start job
14:37:02.343 thread_B finish job
14:37:02.359 thread_C start job

I feel strange that the time is the same for a period of time and over and
over again. Is this normal?
And i found that the time difference is always about 0.016s. Why? (this
confused me a lot as i cant accurately measure time used for a function)
Does it exist a more accurate way to log the time to milliseconds?

Thanks in advance.

Alex

Andrue Cope [TeamB] · Guest

Alex Liu wrote: