Erlang - 调用 io:format 时收到超时消息

Question

我有以下程序。但是，在跟踪生成的进程时，我看到一条带有超时的跟踪消息，如下面的跟踪所示。

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(...) 时，没有收到此消息。有人可以指出可能是什么原因吗？

编辑：我已更新跟踪以包括对所有函数的调用，这可能会有所帮助。

Answer 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 的超时意味着如果消息不存在，您永远不会等待，但您确实会获得超时。我猜这就是你在跟踪中看到的。这不是错误，而是代码的编写方式。这样做没有可行的替代方法。

这意味着在某种程度上您将不得不忽略此超时，或者可能只是接受超时作为程序的自然部分，而不是某种形式的“异常”或错误。

如果我了解它的工作原理。

Answer 2

我的两分钱在这里：如果您阅读 erlang doc for dbg 您也会看到该超时消息，我认为注册用于打印调试消息的 io_server 会产生一个专用进程，该进程可以简化大型阻塞 I/O 跟踪的性能，但是过了一会儿，什么都没有被跟踪，它只是删除了正在侦听的“套接字”（我的意思是从 erlang 传递消息系统的角度来看的套接字）。 实际上，您会看到往返于打印服务器 的 io_request 和 io_reply，我认为您可以简单地将其作为（无用的）进一步调试消息而忽略。