【发布时间】:2014-06-05 23:04:24
【问题描述】:
我在日志文件中观察到一些我无法解释的:
项目中的所有代码都是 ANSI C, 32bit exe 运行在 Windows 7 64bit 上
我有一个与此类似的工作函数,在单线程程序中运行,不使用递归。如图所示,在调试期间包含了日志记录:
//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;
}
上面的函数是从我们的实际代码中简化的,但足以说明问题。
我们偶尔会看到这样的日志条目:
时间/日期戳在左边,然后是message,最后一个字段是duration在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 - 在我使用的环境中,有 UI 计时器,根据定义,它们在主线程中运行。还有其他选项,即创建自己的线程的 AsyncTimer,但在这种情况下,我只使用 UI 计时器。
-
如果箭头是硬编码的,我不明白你可以得到谁
Entering ->和Entering <- -
@ryyker:好的,但目前没有足够的证据可以提供帮助,AFAICS。如果代码真的是单线程的,并且日志功能真的很健全,并且真的没有其他代码可以输出到日志中,那么显然这不会发生(尽管有 UB)。所以充其量,我们只能推测。我认为你需要生成一个minimal test-case。
-
通过调用“WriteToLog()”调用的 MS Win 记录器有多种模式。如果实现了 EVENT_TRACE_FILE_MODE_CIRCULAR 模式,则 MS 文档指出“请注意,在多处理器计算机上,循环日志文件的内容可能会出现乱序。”此外,MS Doc 指出“EVENT_TRACE_NO_PER_PROCESSOR_BUFFERING”模式“使用此模式可以消除事件在使用系统时间在不同处理器上发布时出现乱序的问题。”