How fast can Erlang send messages?

原文地址：http://www.lshift.net/blog/2006/09/10/how-fast-can-erlang-send-messages

My previous post examined Erlang’s speed of process setup and teardown. Here I’m looking at how quickly messages can be sent and received within a single Erlang node. Roughly speaking, I’m seeing 3.4 million deliveries per second one-way, and 1.4 million roundtrips per second (2.8 million deliveries per second) in a ping-pong setup in the same environment as previously - a 2.8GHz Pentium 4 with 1MB cache.

Here’s the code I’m using - time_diff and dotimes aren’t shown, because they’re the same as the code in the previous post:

-module(ipctest).
-export([oneway/0, consumer/0, pingpong/0]).

oneway() ->
    N = 10000000,
    Pid = spawn(ipctest, consumer, []),
    Start = erlang:now(),
    dotimes(N - 1, fun () -> Pid ! message end),
    Pid ! {done, self()},
    receive ok -> ok end,
    Stop = erlang:now(),
    N / time_diff(Start, Stop).

pingpong() ->
    N = 10000000,
    Pid = spawn(ipctest, consumer, []),
    Start = erlang:now(),
    Message = {ping, self()},
    dotimes(N, fun () ->
               Pid ! Message,
               receive pong -> ok end
           end),
    Stop = erlang:now(),
    N / time_diff(Start, Stop).

consumer() ->
    receive
    message -> consumer();
    {done, Pid} -> Pid ! ok;
    {ping, Pid} ->
        Pid ! pong,
        consumer()
    end.

dotimes(0, _) -> done;
dotimes(N, F) ->
    F(),
    dotimes(N - 1, F).

time_diff({A1,A2,A3}, {B1,B2,B3}) ->
    (B1 - A1) * 1000000 + (B2 - A2) + (B3 - A3) / 1000000.0 .

我的实验如下：
root@nd-desktop:~/otp_src_R13B01# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 23
model name      : Pentium(R) Dual-Core  CPU      E5200  @ 2.50GHz
stepping        : 6
cpu MHz         : 1200.000
cache size      : 2048 KB
physical id     : 0
siblings        : 2
core id         : 0
cpu cores       : 2
apicid          : 0
initial apicid  : 0
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 10
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe nx lm constant_tsc arch_perfmon pebs bts pni dtes64 monitor ds_cpl est tm2 ssse3 cx16 xtpr pdcm lahf_lm
bogomips        : 4988.06
clflush size    : 64
power management:

root@nd-desktop:~# erl  -smp disable
Erlang R13B01 (erts-5.7.2) [source] [rq:1] [async-threads:0] [hipe] [kernel-poll:false]

Eshell V5.7.2  (abort with ^G)
1> ipctest:pingpong().
2695648.1187206563
2>
BREAK: (a)bort (c)ontinue (p)roc info (i)nfo (l)oaded
       (v)ersion (k)ill (D)b-tables (d)istribution

trace了下发现大部分的系统调用是
poll([{fd=3, events=POLLIN|POLLRDNORM}, {fd=5, events=POLLIN|POLLRDNORM}, {fd=0, events=POLLIN|POLLRDNORM}], 3, 0) = 0 (Timeout)
clock_gettime(CLOCK_MONOTONIC, {3240948, 582336474}) = 0


^Croot@nd-desktop:~# erl 
Erlang R13B01 (erts-5.7.2) [source] [smp:2:2] [rq:2] [async-threads:0] [hipe] [kernel-poll:false]

Eshell V5.7.2  (abort with ^G)
1> ipctest:pingpong().
709320.2697346376
2>


root@nd-desktop:~# erl  -smp disable +K true
Erlang R13B01 (erts-5.7.2) [source] [rq:1] [async-threads:0] [hipe] [kernel-poll:true]

Eshell V5.7.2  (abort with ^G)
1>
1> ipctest:pingpong().
2801110.2480579205
2>

现在的系统调用是：
clock_gettime(CLOCK_MONOTONIC, {3241209, 575644283}) = 0
epoll_wait(3, {}, 256, 0)               = 0
clock_gettime(CLOCK_MONOTONIC, {3241209, 575983781}) = 0
epoll_wait(3, {}, 256, 0)  

速度从原来的2695648.1187206563变成现在的2801110.2480579205 有10%的提升， 仅仅是因为系统调用从poll到epoll_wait的改变 进出内核的参数少了。

这个速度已经非常理想了 也就是说消息从ping发出-》pong调度-》pong给ping回ok消息-》ping调度，整个流程才花了大概0.4us，这是相当不错的速度。。。

结论： 消息处理很快， 系统调用很费时，beam比beam.smp快很多。

附上erlang进程调度的流程：
1. 处理timer超时
2. 处理子进程退出的情况
3. 处理port_task事件，也就是port的IO事件
4. 如果没有活跃的进程 就sys_schdule阻塞在底层的IO中。
5. 根据process的优先级选出一个进程来调度。

上面epoll_wait的原因就是ping和pong的规约次数到了 让出执行权

附上gdb的断点：

/* Pid ! Message,*/
Breakpoint 2, erts_send_message (sender=0xb7c29aec, receiver=0xb7c2af8c, receiver_locks=0xbfd79790, message=3081450490, flags=0) at beam/erl_message.c:838
838     {
(gdb) c
Continuing.

/*receive pong -> ok end*/
/* ping进程receive的时候阻塞，目前活跃的进程就一个 也就是说pong进程 */
Breakpoint 1, schedule (p=0xb7c29aec, calls=47) at beam/erl_process.c:5785
5785    {
(gdb) c
Continuing.

/* 处理完成消息 释放*/
Breakpoint 3, free_message (mp=0x81f3870) at beam/erl_message.c:53
53      {