系统技术非业余研究

在大家的印象中, gen_tcp:send是个很朴素的函数, 一调用数据就喀嚓喀嚓到了对端. 这是个很大的误解, Erlang的otp文档写的很不清楚. 而且这个功能对于大部分的网络程序是至关重要的, 它的使用对否极大了影响了应用的性能. 我听到很多同学在抱怨erlang的性能低或者出了很奇怪的问题, 很多是由于对系统的不了解, 误用的. 我下面就来解刨下, 文章很长, 而且需要读者熟悉erlang和底层的知识, 跟我来吧.

这篇文章是基于Erlang R13B04这个版本写的.

以下是从gen_tcp文档中摘抄的:

gen_tcp:send(Socket, Packet) -> ok | {error, Reason}
* Socket = socket()
* Packet =

[char()] | binary()
* Reason = posix()
* Sends a packet on a socket.

There is no send call with timeout option, you use the send_timeout socket option if timeouts are desired. See the examples section.

典型的使用如下:

client(PortNo,Message) ->
{ok,Sock} = gen_tcp:connect("localhost",PortNo,[{active,false},
{packet,2}]),
gen_tcp:send(Sock,Message),
A = gen_tcp:recv(Sock,0),
gen_tcp:close(Sock),
A.

很简单是把? 乍一看确实很简单, 但是这是迷惑人的开始.

我们上源代码:

lib/kernel/src/gen_tcp.erl

124send(S, Packet) when is_port(S) ->    %这里可以看出 S是个port
125    case inet_db:lookup_socket(S) of
126        {ok, Mod} ->                  %Mod可能是inet_tcp.erl 或者  inet6_tcp.erl
127            Mod:send(S, Packet);
128        Error ->
129            Error
130    end.

lib/kernel/src/inet_tcp.erl

 49send(Socket, Packet, Opts) -> prim_inet:send(Socket, Packet, Opts). %转给prim_inet模块
 50send(Socket, Packet) -> prim_inet:send(Socket, Packet, []).

erts/preloaded/src/prim_inet.erl

 360send(S, Data, OptList) when is_port(S), is_list(OptList) ->
 361    ?DBG_FORMAT("prim_inet:send(~p, ~p)~n", [S,Data]),
 362    try erlang:port_command(S, Data, OptList) of     <strong>%推给底层的port模块来处理</strong>
 363        false -> % Port busy and nosuspend option passed
 364            ?DBG_FORMAT("prim_inet:send() -> {error,busy}~n", []),
 365            {error,busy};
 366        true -> <strong>% Port模块接受数据</strong>
 367            receive
 368                {inet_reply,S,Status} ->  <strong>%阻塞, 等待回应</strong>
 369                    ?DBG_FORMAT("prim_inet:send() -> ~p~n", [Status]),
 370                    Status
 371            end
 372    catch
 373        error:_Error ->
 374            ?DBG_FORMAT("prim_inet:send() -> {error,einval}~n", []),
 375             {error,einval}
 376    end.
 377
 378send(S, Data) ->
 379    send(S, Data, []).

从上面这几段代码我们可以看出,当我们调用gen_tcp:send的时候, kernel模块会根据gen_tcp socket的类型决定调用相应的模块. 这个模块要么是inet_tcp, 要么是inet6_tcp. 这个模块会把发送请求委托给
prim_inet模块. prim_inet模块首先检查Socket是否合法, 如果合法然后调用erlang:port_command把系统推到ERTS运行期.
这个推的结果有2个: 1. 成功, 进程挂起等待运行期的反馈. 2. 失败,立即返回.
什么情况下会失败呢?
1. 驱动不支持soft_busy, 但是我们用了force标志
2. 驱动已经busy了, 但是我们不允许进程挂起.
Read more…

郎咸武<langxianzhe@163.com>  同学在erlang-china上post了一个问题:
请注意编号为91和92两行运行结果，请问为什么会出现两种结果。
一个抛出 {error,{badmatch,5}}
另一个抛出** exception error: no match of right hand side value 4

root@ubuntu:/usr/src/otp# erl
Erlang R13B04 (erts-5.7.5) [smp:2:2] [rq:2] [async-threads:0] [hipe] [kernel-poll:false
88> X=1.
1
89> try (X=5) of Val ->{normal,Val} catch error:Error -> {error,Error}  end.
{error,{badmatch,5}}
90> try (X=1) of Val ->{normal,Val} catch error:Error -> {error,Error}  end.
{normal,1}
91> try (X=5) of Val ->{normal,Val} catch error:Error -> {error,Error}  end.
{error,{badmatch,5}}
92> try (X=4) of Val ->{normal,Val} catch error:Error -> {error,Error}  end.
** exception error: no match of right hand side value 4
93> self().
<0.36.0>
94> catch try (X=4) of Val  ->{normal,Val} catch error:Error -> {error,Error}  end. %%这个异常是 shell捕获到了 进一步处理后的结果
{'EXIT',{{badmatch,4},[{erl_eval,expr,3}]}}
95> try (X=4) of Val ->{normal,Val} catch error:Error ->  {error,Error}  end.
** exception error: no match of right hand  side value 4
96> self().
<0.36.0>

竟然是EXIT, 这时候shell也换了pid了, 这是怎么回事呢?
由于在shell输入的程序是公司允许的, 我们也可以从出错的stack里面看到是 erl_eval:expr函数异常了.
现在让我们对系统打patch如下:
lib/stdlib/src/erl_eval.erl

 282expr({match,_,Lhs,Rhs0},  Bs0, Lf, Ef, RBs) ->
 283    {value,Rhs,Bs1} = expr(Rhs0, Bs0,  Lf, Ef, none),
 284    case match(Lhs, Rhs, Bs1) of
 285         {match,Bs} ->
 286            ret_expr(Rhs, Bs, RBs);
 287        nomatch ->
 288            io:format("expr nomatch->pid:~p~n~p~n",[self(), Rhs]),   %%添加诊断
 289             erlang:raise(error, {badmatch,Rhs}, stacktrace())
 290    end;

erts/emulator/beam/bif.c

1142/**********************************************************************/
1143/*  raise an exception of given class, value and  stacktrace.
1144  *
1145 * If there is an error in the argument  format,
1146 * return the atom 'badarg'  instead.
1147 */
1148Eterm
1149raise_3(Process *c_p, Eterm class,  Eterm value, Eterm stacktrace) {
...
1222     erts_print(ERTS_PRINT_STDOUT, NULL, "raise->proc:%T\nclass=%T\nvalue=%T\nstacktrace=%T\n", c_p->id, class, value,  c_p->ftrace); /*添加诊断*/
1223    BIF_ERROR(c_p, reason);
...
}

然 后我们在运行上面的语句:

root@ubuntu:~/otp#  bin/erl
Erlang R13B04 (erts-5.7.5) [source]  [smp:2:2] [rq:2]  [async-threads:0] [kernel-poll:false]

Eshell  V5.7.5  (abort with  ^G)
1> X=1.
 1
2>  try (X=5) of Val ->{normal,Val}  catch error:Error ->  {error,Error}  end.
expr nomatch->pid:<0.32.0>
5
raise->proc:<0.32.0>
class=error
value={badmatch,5}
stacktrace=[[{erl_eval,expr,3}
{error,{badmatch,5}}
3>  try  (X=4) of Val ->{normal,Val} catch  error:Error -> {error,Error}   end.
expr nomatch->pid:<0.32.0>
4
raise->proc:<0.32.0>
class=error
value={badmatch,4}
stacktrace=[[{erl_eval,expr,3}]|-000000000000000016]
raise->proc:<0.32.0>
class=error
value={badmatch,4}
stacktrace=[[{erl_eval,expr,3}]|-000000000000000016]

很奇怪的是第3句raise了2次. 让我们回到程序好好看下:

X=1.   %%这行绑定了一个变量X=1
try (X=5) of Val ->{normal,Val} catch  error:Error -> {error,Error}  end.   %%这行由于异常会试图绑定变量Error={badmatch,5}, 由于之前Error不存在, 绑定成功.
try  (X=4) of Val ->{normal,Val} catch error:Error -> {error,Error}   end.   %%这行由于异常会绑定了变量Error={badmatch,4}, 由于Error存在,  而且值是{badmatch,5},所以这时候catch就出
现异常了,  往外抛出{'EXIT',{{badmatch,4},[{erl_eval,expr,3}]}}.

这 下我们明白了, 是这个catch惹的祸了.
我们再实验下我们的分析:

root@ubuntu:~#  erl
Erlang R13B04 (erts-5.7.5) [source] [smp:2:2] [rq:2]  [async-threads:0] [hipe] [kernel-poll:false]

Eshell V5.7.5   (abort with ^G)
1> X=1.
1
2> b().
X = 1
ok
3>  try (X=5) of Val ->{normal,Val} catch error:Error ->  {error,Error}  end.
{error,{badmatch,5}}
4> b().
Error =  {badmatch,5}
X = 1
ok
5> try (X=4) of Val ->{normal,Val}  catch error:Error -> {error,Error}  end.
** exception error: no  match of right hand side value 4
6> f(Error).
ok
7>  b().
X = 1
ok
8> try (X=4) of Val ->{normal,Val}  catch error:Error -> {error,Error}  end.
{error,{badmatch,4}}
9>

Bingo成功.
结论: 要非常小心Erlang语法的变量绑定,在不同的路线会有不同的绑定,容易出问题.

参考Talk http://www.erlang-factory.com/upload/presentations/238/ErlangFView postactorySFBay2010-KennethLundin.pdf
摘抄我感兴趣的:

R14要实现的:

1. June 16: R14A, a beta release
2. Multi-core performance improvements

• – optimized rwlocks
• – delayed deallocation
• – ”lock-free” process table

3. NIF improvements (Native Implemented Function)

• – sending messages from a NIF
• – crypto application as NIFs, now using a driver.

4. search in binaries (as of EEP-31)

• – new module called binary with functions: match, matches, split, replace, longest_common_prefix, … part, at, copy, first,last

5. new SSL ready to replace old SSL
6. improved Reltool

• – for easy creation of minimal target systems and standalone deployments from an installed development system.

7. Tentative

• –Parameterized modules officially supported and with more efficient implementation.

Longer term plans:
1. More multi core performance improvements

• – lock free pre-allocators (thread specific pre allocated buffers)
• – Scheduler specific mseg_alloc reducing lock contention and necessary for future NUMA optimizations. Intel Nehalem, AMD Opteron

2. Clustered shared heap or other solution to allow parallell computing on large sets of data avoiding copying.
3 . New XML-schema/dtd validator complementing the XML SAX parser we already have.
4. SMP optimizations in existing applications (Mnesia, ASN.1 …)
5. Improved eprof profiler

Megaco/H.248 is a protocol for control of elements in a physically decomposed multimedia gateway, enabling separation of call control from media conversion. A Media Gateway Controller (MGC) controls one or more Media Gateways (MG).

Megaco有非常清晰的日志和诊断供我们参考, 精细到几行代码一个诊断信息, 非常好的风格. 有了这些信息对系统的运行完全了如指掌.

有3种方式:
1. 大量的调试日志, 在DEBUG方式下, 会有大量的系统允许期间的轨迹和消息

%%%----------------------------------------------------------------------                                                                                                                         %%% Debug                                                                                                                                                                                                      
%%%----------------------------------------------------------------------  
-ifdef(megaco_debug).                                                                               
-define(d(F,A), io:format("~w: " ++ F ++ "~n",[?MODULE|A])). 
-else.
-define(d(F,A), ok).
-endif.

用起来很方便, 摘抄一段如下

?d("encode(~p) -> entry with"
"~n   PackageItem: ~p"
"~n   SubItem:     ~p", [Scope, PackageItem, SubItem]),

2. 异常日志, 用于记录程序允许中间产生的各种各样的异常, 便于事后调查.

%%%----------------------------------------------------------------------                                                                                                                         %%% Error/warning/info message macro(s)                                                                                                                                                                        
%%%----------------------------------------------------------------------                                                                                                                         -define(megaco_info(F, A),                                                                                                                                                                                     
        (catch error_logger:info_msg("[ ~w : ~w : ~p ] ~n" ++ F ++ "~n", [?APPLICATION, ?MODULE, self()|A]))).
                                                                                                                                                                                                               
-define(megaco_warning(F, A),                                                                                                                                                                                  
        (catch error_logger:warning_msg("[ ~w : ~w : ~p ] ~n" ++ F ++ "~n", [?APPLICATION, ?MODULE, self()|A]))).
                                                                                                                                                                                                               
-define(megaco_error(F, A),                                                                                                                                                                                    
        (catch error_logger:error_msg("[ ~w : ~w : ~p ] ~n" ++ F ++ "~n",[?APPLICATION, ?MODULE, self()|A]))). 

使用, 摘抄一段如下

warning_msg(F, A) ->                                                                                
   ?megaco_warning("Transaction sender: " ++ F, A). 
error_msg(F, A) ->                                       
   ?megaco_error("Transaction sender: " ++ F, A).

3. Event Trace机制
先进的trace能够让系统的消息交互,运行轨迹以可视的方式体现在用户面前.

%%%----------------------------------------------------------------------                                                                                                                         
%%% Event Trace                                                                                                                                                                                                
%%%----------------------------------------------------------------------                                                                                                                         -ifdef(megaco_trace_io).
-define(report(Level, C, Label, Contents),
        io:format("*** [~s] ~p ~p *** "
                  "~n   ~p[~p] " ++ Label ++
                  "~n   ~p"
                  "~n   ~p"
                  "~n",
                  [megaco:format_timestamp(now()),
                   self(), Level, ?MODULE, ?LINE, C, Contents])).
-else.
-define(report(Level, C, Label, Contents),
        megaco:report_event(Level, ?APPLICATION, Label,
                            [{line, ?MODULE, ?LINE}, C | Contents])).
-endif.

-define(report_important(C, Label, Contents), ?report(20, C, Label, Contents)).
-define(report_verbose(  C, Label, Contents), ?report(40, C, Label, Contents)).
-define(report_debug(    C, Label, Contents), ?report(60, C, Label, Contents)).
-define(report_trace(    C, Label, Contents), ?report(80, C, Label, Contents)).

使用, 摘抄一段如下

?report_trace(ReceiveHandle, "callback: syntax error", [ErrorDesc, Error]), 

实际效果图(点击放大):

总结: ET很强大, 而且是专门为Megaco开发的, 目的就是能够可视化看到Megaco系统组件见的消息流程交互.

抄书:otp_doc_html_R13B04/lib/tools-2.6.5.1/doc/html /lcnt_chapter.html#id2252207

lcnt – The Lock Profiler

Internally in the Erlang runtime system locks are used to protect resources from being updated from multiple threads in a fatal way. Locks are necessary to ensure that the runtime system works properly but it also introduces a couple of limitations. Lock contention and locking overhead.

With lock contention we mean when one thread locks a resource and another thread, or threads, tries to acquire the same resource at the same time. The lock will deny the other thread access to the resource and the thread will be blocked from continuing its execution. The second thread has to wait until the first thread has completed its access to the resource and unlocked it. The lcnt tool measures these lock conflicts.

Locks has an inherent cost in execution time and memory space. It takes time initialize, destroy, aquiring or releasing locks. To decrease lock contention it some times necessary to use finer grained locking strategies. This will usually also increase the locking overhead and hence there is a tradeoff between lock contention and overhead. In general, lock contention increases with the number of threads running concurrently. The lcnt tool does not measure locking overhead.

5.1 Enabling lock-counting

For investigation of locks in the emulator we use an internal tool called lcnt (short for lock-count). The VM needs to be compiled with this option enabled. To enable this, use:

cd $ERL_TOP
./configure --enable-lock-counter

Another way to enable this alongside a normal VM is to compile it at emulator directory level, much like a debug build. To compile it this way do the following,

cd $ERL_TOP/erts/emulator
make lcnt FLAVOR=smp

and then starting Erlang with,

$ERL_TOP/bin/cerl -lcnt

To verify that you lock-counting enabled check that [lock-counting] appears in the status text when the VM is started.

Erlang R13B03 (erts-5.7.4) [64-bit] [smp:8:8] [rq:8] [async-threads:0] [hipe]
[kernel-poll:false] [lock-counting]

5.2 Getting started

Once you have a lock counting enabled VM the module lcnt can be used. The module is intended to be used from the current running nodes shell. To access remote nodes use lcnt:clear(Node) and lcnt:collect(Node).

All locks are continuously monitored and its statistics updated. Use lcnt:clear/0 to initially clear all counters before running any specific tests. This command will also reset the duration timer internally.

To retrieve lock statistics information use, lcnt:collect/0,1. The collect operation will start a lcnt server if it not already started. All collected data will be built into an erlang term and uploaded to the server and a duration time will also be uploaded. This duration is the time between lcnt:clear/0,1 and lcnt:collect/0,1.

Once the data is collected to the server it can be filtered, sorted and printed in many different ways.

See the reference manual for a description of each function.

其实Erts的Async做的很不错的, 相当的完备, 性能又高. 但是奇怪的是只有文件driver才真正利用到了这个优势. 难道是OTP团队的人,不想为了性能把事情搞的复杂了. Driver和最近加入的NIF都提供了大量的线程,锁,同步的原语来支持最大的程度的利用单线程的优势. 俺会做小白鼠来参试这些被遗忘的设施.

由于R13B以后, Erlang的分布协议修改了格式, 添加了Atom Cache, erlsnoop在新版本下无法使用, 我特地打了patch, 使得它支持最新的版本,源码在附件中下载.

在erlang的邮件列表上看到：
Have you tried putting a snoop to see whether the delay is on the
sending/receiving side?

This might be useful: http://www.erlang.org/contrib/erlsnoop-1.0.tgz

去http://www.erlang.org/contrib/看了下 模块真不少 下载了erl_snoop

先安装lib-pcap

# yum install libpcap-devel
# yum install libpcap

但是编译出错:
ip.c:77: error: label at end of compound statement
随便在default: 后面加个return 0;

utils.c: In function ‘gmt2local’:
utils.c:26: error: storage size of ‘sgmt’ isn’t known
utils.c:28: warning: implicit declaration of function ‘time’
utils.c:31: error: dereferencing pointer to incomplete type
utils.c:31: warning: implicit declaration of function ‘gmtime’
utils.c:31: error: invalid type argument of ‘unary *’
utils.c:32: warning: implicit declaration of function ‘localtime’
utils.c:32: warning: assignment makes pointer from integer without a cast
utils.c:34: error: dereferencing pointer to incomplete type
utils.c:34: error: dereferencing pointer to incomplete type
utils.c:35: error: dereferencing pointer to incomplete type
utils.c:35: error: dereferencing pointer to incomplete type
utils.c:42: error: dereferencing pointer to incomplete type
utils.c:42: error: dereferencing pointer to incomplete type
utils.c:43: error: dereferencing pointer to incomplete type
utils.c:43: error: dereferencing pointer to incomplete type
utils.c:26: warning: unused variable ‘sgmt’
make: *** [utils.o] Error 1

加个 #include

搞定 运行

[root@test98 erlsnoop-1.0]# ./erlsnoop -hpnkt
Erlsnoop 1.0 (Mar  4 2008)
using interface eth0 (mtu=1500)
using filter "tcp"
option -? gets help
type ^C to quit

[ 192.168.0.98:44683 (x@192.168.0.98) > 192.168.0.243:30141 (y@192.168.0.243) ] 160
  REG_SEND from: #Pid<x@192.168.0.98.11.0.2> to: global_name_server

[ 192.168.0.98:44683 (x@192.168.0.98) > 192.168.0.243:30141 (y@192.168.0.243) ] 49
  MONITOR from: #Pid<x@192.168.0.98.36.0.2> to: net_kernel
   ref: #Ref<x@192.168.0.98.46.0.0.2>

[ 192.168.0.243:30141 (y@192.168.0.243) > 192.168.0.98:44683 (x@192.168.0.98) ] 161
  REG_SEND from: #Pid<y@192.168.0.243.11.0.2> to: global_name_server

[ 192.168.0.98:44683 (x@192.168.0.98) > 192.168.0.243:30141 (y@192.168.0.243) ] 84
  REG_SEND from: #Pid<x@192.168.0.98.36.0.2> to: net_kernel

效果不错的哦。可以看到erlang的交互信息， 相信的请看README.txt

下载erlsnoop-1.1