我观察到一个日志文件的东西,我无法解释:执行流程 - 可能在退出前两次输入功能?
项目的所有代码被ANSI C,32位exe文件在Windows 7 64位
运行我have类似这样的工人功能在一个单线程程序运行时,不使用递归。在调试过程中记录被包括,如下所示:
//This function is called from an event handler
//triggered by a UI timer similar in concept to
//C# `Timer.OnTick` or C++ Timer::OnTick
//with tick period set to a shorter duration
//than this worker function sometimes requires
int LoadState(int state)
{
WriteToLog("Entering ->"); //first call in
//...
//Some additional code - varies in execution time, but typically ~100ms.
//...
WriteToLog("Leaving <-");//second to last call out
return 0;
}
上面的函数是从我们的实际代码简化但是足以用于说明问题。
我们有时看到的日志条目,如本:
凡时间/日期邮票是在左边,然后消息,最后一个字段是时间在clock()
调用日志功能之间的滴答声。此日志记录表明该函数在退出之前已连续输入两次。
没有递归,在单线程程序,它是如何(或是)可能执行流程可以两次进入功能,完成了第一次调用之前?
编辑:(显示日志功能的顶部调用)
int WriteToLog(char* str)
{
FILE* log;
char *tmStr;
ssize_t size;
char pn[MAX_PATHNAME_LEN];
char path[MAX_PATHNAME_LEN], base[50], ext[5];
char LocationKeep[MAX_PATHNAME_LEN];
static unsigned long long index = 0;
if(str)
{
if(FileExists(LOGFILE, &size))
{
strcpy(pn,LOGFILE);
ManageLogs(pn, LOGSIZE);
tmStr = calloc(25, sizeof(char));
log = fopen(LOGFILE, "a+");
if (log == NULL)
{
free(tmStr);
return -1;
}
//fprintf(log, "%10llu %s: %s - %d\n", index++, GetTimeString(tmStr), str, GetClockCycles());
fprintf(log, "%s: %s - %d\n", GetTimeString(tmStr), str, GetClockCycles());
//fprintf(log, "%s: %s\n", GetTimeString(tmStr), str);
fclose(log);
free(tmStr);
}
else
{
strcpy(LocationKeep, LOGFILE);
GetFileParts(LocationKeep, path, base, ext);
CheckAndOrCreateDirectories(path);
tmStr = calloc(25, sizeof(char));
log = fopen(LOGFILE, "a+");
if (log == NULL)
{
free(tmStr);
return -1;
}
fprintf(log, "%s: %s - %d\n", GetTimeString(tmStr), str, GetClockCycles());
//fprintf(log, "%s: %s\n", GetTimeString(tmStr), str);
fclose(log);
free(tmStr);
}
}
return 0;
}
你是如何确认只有一个线程的?特别是,你如何知道UI定时器没有创建一个单独的上下文来执行回调? – jxh
@jxh - 在我使用的环境有定时器在主线程中运行的UI定时器,还有其他选项,例如AsyncTimer,它创建了自己的线程,但在这种情况下,我只使用UI定时器 – ryyker
关于快速执行代码,有时候输出流可能会失序,在每次写入之后尝试fflush(stdout)(或者发送输出的时候),看看实际发生了什么。 –