2012-02-14 71 views
1

我有以下程序。但是,在追蹤生成的進程時,我會看到一條帶有超時的跟蹤消息,如以下跟蹤中所示。Erlang - 調用io時接收超時消息:格式

start() -> 
    register(addone, spawn(addone, loop, [])). 

loop() -> 
receive 
    {request, Pid, Msg} -> 
     io:format("log ~n", []), 
     loop(); 
    {stop, _Reason} -> 
     stop 
end. 

我執行這個過程具有以下功能:觀察

run() -> 
addone:start(), 
dbg:start(), 
dbg:tracer(), 
dbg:p(whereis(addone), [c,m]), 
dbg:tpl({'_','_','_'},[{'_',['true'],[{'silent', 'false'}]}]), 
addone:request(4). 

跟蹤如下:

1> addone_scenarios:run(). 
log 
(<0.32.0>) << {request,<0.30.0>,4} 
(<0.32.0>) call io:format("log ~n",[]) 
(<0.32.0>) call io:default_output() 
(<0.32.0>) call erlang:group_leader() 
(<0.32.0>) call io:format(<0.23.0>,"log ~n",[]) 
(<0.32.0>) call io:o_request(<0.23.0>,{format,"log ~n",[]},format) 
(<0.32.0>) call io:request(<0.23.0>,{format,"log ~n",[]}) 
(<0.32.0>) call io:io_request(<0.23.0>,{format,"log ~n",[]}) 
(<0.32.0>) call io:bc_req(<0.23.0>,{put_chars,unicode,io_lib,format,["log ~n",[]]},false) 
(<0.32.0>) call net_kernel:dflag_unicode_io(<0.23.0>) 
(<0.32.0>) call io:execute_request(<0.23.0>,{false,{put_chars,unicode,io_lib,format,["log ~n",[]]}}) 
(<0.32.0>) call erlang:monitor(process,<0.23.0>) 
(<0.32.0>) <0.23.0> ! {io_request,<0.32.0>,<0.23.0>, 
          {put_chars,unicode,io_lib,format,["log ~n",[]]}} 
(<0.32.0>) call io:wait_io_mon_reply(<0.23.0>,#Ref<0.0.0.29>) 
(<0.32.0>) << {io_reply,<0.23.0>,ok} 
(<0.32.0>) call erlang:demonitor(#Ref<0.0.0.29>) 
(<0.32.0>) << timeout 
(<0.32.0>) call addone:loop() 

什麼奇怪的是,收到超時跟蹤消息。當我刪除io:format(...)時,未收到此消息。有人可以指出什麼是可能的原因嗎?

編輯:我已更新跟蹤以包含所有功能的調用,也許它可能有所幫助。

回答

0

我的兩分錢在這裏:如果您閱讀erlang doc for dbg,您也會看到該超時消息,我認爲註冊打印調試消息的io_server產生了一個專用的進程,可以緩解大型阻塞I/O跟蹤的性能,但過了一段時間,沒有任何東西被追蹤,它只是放棄偵聽的「套接字」(我的意思是從erlang傳遞消息系統的角度來看套接字)。 你的確看到io_request和io_reply並從< 0.23.0>是打印服務器,我想你可以簡單地忽略它作爲一個(無用)進一步調試消息。

+0

我忽略這個跟蹤消息的問題是,我正在構建一個工具來分析程序的痕跡,並根據它收到的內容採取行動..所以我不能選擇哪些超時消息我可以忽略,哪些不是不幸的 – aseychell 2012-02-14 18:09:38

1

在IO模塊,其中有在功能io:wait_io_mon_reply/2其中它等待回覆到IO請求消息超時中的唯一位置。爲了確保客戶端進程不會掛起,io進程已經被監視以檢測它在返回應答之前死亡的情況。該io:wait_io_mon_reply/2必須處理的它可以接收也清理的情況下,消息隊列它得到多方面的回報,例如監控被關閉之前都回復消息和死亡消息的發送過程的各種情況。由於erlang通信的非確定性異步特性,這發生並且必須被照顧。

處理這種標準方式是通過做(取直出功能):

receive 
    {io_reply, From, Reply} -> 
     erlang:demonitor(Mref), 
     receive 
      {'DOWN', Mref, _, _, _} -> true 
     after 0 -> true 
     end, 
     Reply; 

使用的0超時意味着你永遠等待,如果該消息是不存在的,但你得到超時。我猜測這就是你在跟蹤中看到的。這不是一個錯誤,而只是編寫代碼的方式。沒有這樣做的可行替代方案。

這意味着,在某種程度上,你將不得不忽略此超時,或者只是接受超時作爲該計劃的一個自然組成部分,而不是某種形式的「異常」或錯誤的。

如果我已經明白它是如何工作的。

+0

似乎是有效的原因..最有可能的,我不得不忽略超時消息。 – aseychell 2012-02-14 23:40:48

+0

會調用'erlang:demonitor(Mref,[flush])'而不是避免這個超時?或者它仍然會出現在痕跡中? – legoscia 2012-02-15 14:30:53

+0

在這種情況下,它應該將其刪除,但這僅僅是'io:wait_io_mon_reply/2'中的**一個**,並且在其他情況下不起作用。查看'io'模塊中的函數。 – rvirding 2012-02-16 23:43:58