2014-04-21 58 views
3

我觀察到一個日誌文件的東西,我無法解釋:執行流程 - 可能在退出前兩次輸入功能?

項目的所有代碼被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; 
} 

上面的函數是從我們的實際代碼簡化但是足以用於說明問題。

我們有時看到的日誌條目,如本:

enter image description here

時間/日期郵票是在左邊,然後消息,最後一個字段是時間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; 
} 
+4

你是如何確認只有一個線程的?特別是,你如何知道UI定時器沒有創建一個單獨的上下文來執行回調? – jxh

+0

@jxh - 在我使用的環境有定時器在主線程中運行的UI定時器,還有其他選項,例如AsyncTimer,它創建了自己的線程,但在這種情況下,我只使用UI定時器 – ryyker

+0

關於快速執行代碼,有時候輸出流可能會失序,在每次寫入之後嘗試fflush(stdout)(或者發送輸出的時候),看看實際發生了什麼。 –

回答

1

我問這個問題的時候想知道是否有C標準,允許的一些模糊的一部分執行流程進入一個函數不止一次在沒有先退出(因爲多線程或遞歸不在場)

您的意見,我相信,哈已經明確回答了這個問題。從什麼@Oli查爾斯沃思在一個評論說借鑑,他概括起來相當不錯:

如果代碼確實是單線程的,和對數函數是真正理智的,而且也確實沒有其他的代碼可以輸出到日誌,那麼顯然這不會發生(UB儘管)。

但由於實際日誌文件(我不能張貼特殊原因),在多個場合已證實了這一格局,@Oli查爾斯沃思列出的條件之一,實際上不是我們的軟件如此。在這一點上考慮到日誌功能是理智並且是唯一的輸入到文件中,我最好的猜測,是考慮@jxh建議的替代context/Fiber可能性:

「主線程只有「可以表示多種事物。該庫仍可能在POSIX上使用<ucontext.h>,或者在Windows上使用Fibers。

因此,我會將這個問題發佈到我的環境的供應商,特別是如果他們的UI定時器以允許由於光纖或線程並行呼叫的方式運行。

如果有興趣,我也會更新這個答案與他們的迴應。

編輯,顯示的結論:

事實證明,執行流程的雙重進入一個函數的原因是隱含的遞歸。也就是說,雖然worker函數沒有明確引用它,但,它被指定爲兩個獨立事件生成器的事件處理程序。加上過程系統事件(在我們的環境中可用的函數迫使隊列中的事件現在處理),可以(並且確實)導致遞歸執行流進入事件處理函數。以下是在我們的環境中具有UI定時器和系統事件之間關係專業知識的人員的引用:

「定時器事件嵌套」的作用與執行流程在離開前兩次進入函數等同。基本上,它和基本的遞歸是一樣的:當你在一個函數中時,你調用了相同的函數。這種情況與基本遞歸的唯一區別在於遞歸調用是隱式的(通過ProcessSystemEvents)而不是顯式的。但最終結果是一樣的。「

+0

很高興你從圖書館實施的角度回答了你的問題。但是,請注意,由於您在問題中的問題陳述(以及您在本答案的第一段中提到的問題)明確排除了遞歸,所以沒有人會以此爲答案。 – jxh

+1

@jxh - 這不是我特意排除遞歸的意圖。我當時知道我沒有在我的代碼中使用任何可以遞歸的語法。另外,在我發佈這篇文章的時候,我不知道實際發生的事情是否會發生。當有人解釋我們庫中的定時器回調實現如何工作時,_implicit遞歸_的概念首次呈現給我。你(和奧利)是第一個發表聲明的人,他們在你的評論中發現了真正的問題,我在文章中引用了這些內容。 – ryyker