系统技术非业余研究

公司培训用的文档, 对于Erlang的VM会有个大体的认识, 方便设计和使用Erlang.
点解下载pdf格式的文档

在Erlang-china的邮件列表上看到这样的问题:

我的服务经常发生这样的错误,举例:
Error in process <0.33.0> with exit value: {badarg,[{erlang,’++’,[undefined,[{“37”}]]},{groups,doWork,1},
{groups,doWork,1},{groups,manage_clients,1}]}

大意明白,但问题是我使用匹配机制时没考虑到多个函数”doWork/1″出错无法定位到其中一个,这该如何是好?
Erlang是否会像其它语言一样提示某一行出错?

这个问题确实很常见, Erlang的运行期没有给出出错的具体行数, 这给我们定位问题带来了很大的麻烦.

有先驱给出了这样的解决方案 http://mryufeng.javaeye.com/blog/368507 但是这个模块已经很老了, 过时不维护了.

这里我给出另外一个方案, 利用erlang现有的模块来实现的: cover + dbg

cover的工作原理可以参考这篇文章 http://mryufeng.javaeye.com/blog/482204.

原理就是cover编译过的模块会在每行执行前, 先执行ets:update_counter(cover_internal_data_table,{bump,Mod,Fun,1,1,Line},1) 来更新模块某行的执行次数.
那么我们只要截取 ets:update_counter这个动作, 我们就知道改模块最后的执行行, 也就是异常所在的行.

Ok, 原理介绍完毕, 上菜.

[root@centos ~]# cat line.erl

-module(line).
-export([dbg/1]).
-include_lib("stdlib/include/ms_transform.hrl").

dbg(Mod)->
    cover:compile(Mod),
    dbg:tracer(),
    dbg:p(all, [call]),
    dbg:tpl(ets,
            update_counter,
            dbg:fun2ms(fun([_,{bump,Mod,_,_,_,_},1]) ->
                               return_trace()
                       end)),
    ok.

[root@centos ~]# cat hello.erl

-module(hello).
-export([start/0]).

start()->
    a=a,
    A=2,
    C=3,
    A=C-1,
    C=A+1,
    io:format("hello world~n",[]),
    test(C),
    ok.


test(C)->
    A=4,
    A=C,  % Error is on this line.
    ok.

我们可以看到这个hello模块会在hello:test发生异常, A=C这个地方是具体位置. 现在让我们找到行号:

[root@centos ~]# erl
Erlang R13B02 (erts-5.7.3) [source] [64-bit] [smp:2:2] [rq:2] [async-threads:0] [hipe] [kernel-poll:false]

Eshell V5.7.3  (abort with ^G)
1> line:dbg(hello).
ok
2> hello:start().
hello world
** exception error: no match of right hand side value 3
     in function  hello:test/1
     in call from hello:start/0
4> (<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,start,0,1,5},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,start,0,1,6},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,start,0,1,7},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,start,0,1,8},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,start,0,1,9},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,start,0,1,10},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,start,0,1,11},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,test,1,1,16},1)
(<0.34.0>) returned from ets:update_counter/3 -> 1
(<0.34.0>) call ets:update_counter(cover_internal_data_table,{bump,hello,test,1,1,17},1)   %这里我们看到出错的行号
(<0.34.0>) returned from ets:update_counter/3 -> 1
3> 
BREAK: (a)bort (c)ontinue (p)roc info (i)nfo (l)oaded
       (v)ersion (k)ill (D)b-tables (d)istribution

我们可以看到最后一次执行hello模块的行数是17.

Bingo!

我们在编码的时候, 通常会好奇, 这时候需要观察erl源码生成的VM opcode. Erlang的VM是register based的VM, 生产的opcode很容易理解.
生成汇编格式有2种方式:
1. 从源码生成抽象码. erlc +”‘S'” mod.erl, 生成mod.S
2. 从beam生成Opcode. 未公开的功能. erts_debug:df 参数M或者 M, F, 生成mod.dis

来吧,实践下:

root@ubuntu:~/exam# ls
eg.erl
root@ubuntu:~/exam# erlc +"'S'" eg.erl
root@ubuntu:~/exam# erlc eg.erl
root@ubuntu:~/exam# erl
Erlang R14A (erts-5.8) [source] [smp:2:2] [rq:2] [async-threads:0] [hipe] [kernel-poll:false] [lock-counting]

Eshell V5.8  (abort with ^G)
1>  erts_debug:df(eg).
ok
2> 
User switch command
 --> q
root@ubuntu:~/exam# ls eg*
eg.beam  eg.dis  eg.erl  eg.S

我们得到了eg.S, eg.dis这2个反汇编的结果. 我们再来参观下.
先看源码:
root@ubuntu:~/exam# cat eg.erl

-module(eg).
-import(lists).
-import(lists,[sum/1]).
-compile(export_all).


kilo_byte() ->
    kilo_byte(10, [42]).
kilo_byte(0, Acc) ->
    Acc;
kilo_byte(N, Acc) ->
    kilo_byte(N-1, [Acc|Acc]).


loop()->
    sum(lists:seq(1,100)),
    loop().

中间汇编码, 供transform进行处理和编译器进一步生成opcode.
root@ubuntu:~/exam# cat eg.S

{module, eg}.  %% version = 0

{exports, [{kilo_byte,0},
           {kilo_byte,2},
           {loop,0},
           {module_info,0},
           {module_info,1}]}.

{attributes, []}.

{labels, 12}.


{function, kilo_byte, 0, 2}.
  {label,1}.
    {func_info,{atom,eg},{atom,kilo_byte},0}.
  {label,2}.
    {move,{literal,"*"},{x,1}}.
    {move,{integer,10},{x,0}}.
    {call_only,2,{f,4}}.


{function, kilo_byte, 2, 4}.
  {label,3}.
    {func_info,{atom,eg},{atom,kilo_byte},2}.
  {label,4}.
    {test,is_eq_exact,{f,5},[{x,0},{integer,0}]}.
    {move,{x,1},{x,0}}.
    return.
  {label,5}.
    {gc_bif,'-',{f,0},2,[{x,0},{integer,1}],{x,0}}.
    {test_heap,2,2}.
    {put_list,{x,1},{x,1},{x,1}}.
    {call_only,2,{f,4}}.


{function, loop, 0, 7}.
  {label,6}.
    {func_info,{atom,eg},{atom,loop},0}.
  {label,7}.
    {allocate,0,0}.
    {move,{integer,100},{x,1}}.
    {move,{integer,1},{x,0}}.
    {call_ext,2,{extfunc,lists,seq,2}}.
    {call_ext,1,{extfunc,lists,sum,1}}.
    {call_last,0,{f,7},0}.


{function, module_info, 0, 9}.
  {label,8}.
    {func_info,{atom,eg},{atom,module_info},0}.
  {label,9}.
    {move,{atom,eg},{x,0}}.
    {call_ext_only,1,{extfunc,erlang,get_module_info,1}}.


{function, module_info, 1, 11}.
  {label,10}.
    {func_info,{atom,eg},{atom,module_info},1}.
  {label,11}.
    {move,{x,0},{x,1}}.
    {move,{atom,eg},{x,0}}.
    {call_ext_only,2,{extfunc,erlang,get_module_info,2}}.

VM opcode形式, VM就是来解释运行这些code的

 
root@ubuntu:~/exam# cat eg.dis
B5146074: i_func_info_IaaI 0 eg kilo_byte 0 
B5146088: move_cx "*" x(1) 
B5146094: i_move_call_only_fcr eg:kilo_byte/2 10 x(0) 

B51460A0: i_func_info_IaaI 0 eg kilo_byte 2 
B51460B4: i_is_eq_immed_frc f(B51460C8) x(0) 0 
B51460C0: move_return_xr x(1) x(0) 
B51460C8: i_fetch_rc x(0) 1 
B51460D0: i_minus_jId j(00000000) 2 x(0) 
B51460E0: test_heap_II 2 2 
B51460EC: put_list_xxx x(1) x(1) x(1) 
B51460F4: i_call_only_f eg:kilo_byte/2 

B51460FC: i_func_info_IaaI 0 eg loop 0 
B5146110: allocate_tt 0 0 
B5146118: move_cx 100 x(1) 
B5146124: i_move_call_ext_cre 1 x(0) lists:seq/2 
B5146130: i_call_ext_e lists:sum/1 
B5146138: i_call_last_fP eg:loop/0 0 

B5146144: i_func_info_IaaI 0 eg module_info 0 
B5146158: move_cr eg x(0) 
B5146160: allocate_tt 0 1 
B5146168: call_bif1_e erlang:get_module_info/1 
B5146170: deallocate_return_P 0 

B5146178: i_func_info_IaaI 0 eg module_info 1 
B514618C: move_rx x(0) x(1) 
B5146194: move_cr eg x(0) 
B514619C: allocate_tt 0 2 
B51461A4: call_bif2_e erlang:get_module_info/2 
B51461AC: deallocate_return_P 0 

收工!

我们通常在使用port的时候, 需要把他同其他的上下文关联起来, 以便在port给我们发生数据的时候, 我们能根据绑定的上下文, 知道如何处理数据.
有2种办法:
1. 用ets来保存{Port, Ctx},这个比较慢, 每次都要查表.
2. 用Port本身的空间来保存Ctx. erlang:port_set_data 和erlang:port_get_data就是干这类事情的, 一步到位, 多核free.

不啰嗦上代码:

root@ubuntu:~# echo test >> test.dat
root@ubuntu:~# erl
Erlang R14A (erts-5.8) [source] [smp:2:2] [rq:2] [async-threads:0] [hipe] [kernel-poll:false] [lock-counting]

Eshell V5.8  (abort with ^G)
1>  {ok,{_,_,{Port,_}}} = file:open("test.dat", [read,raw]).
{ok,{file_descriptor,prim_file,{#Port<0.498>,7}}}
2> erlang:port_info(Port).
[{name,"efile"},
 {links,[<0.31.0>]},
 {id,498},
 {connected,<0.31.0>},
 {input,9},
 {output,11}]
3> erlang:port_set_data(Port, abcdefg).
true
4>  erlang:port_get_data(Port).
abcdefg

注意: gen_tcp和gen_udp等的port_data已经被使用了.

收工!

我们开发好了一个软件的时候,通常是经过严格测试的,才分发给用户使用, 但是即使这样也不能保证用户的环境和我们的相同, 我们的软件还是会失败的. 问题是如何诊断这些问题.
通常的做法是写log,这是个很有效的方式. 但是写log要代码支持,而且会带来负面的性能影响. Erlang提供了强大的Trace机制, 帮助我们解决这个问题. OTP本身有很多模块利用了这个技术手段,我们从ftp模块学习下:

上代码:
lib/inets/src/ftp/ftp.erl

 771    %% Maybe activate dbg                                                                                                                                                                                  
 772    case key_search(debug, Options, disable) of
 773        trace ->
 774            dbg:tracer(),
 775            dbg:p(all, [call]),  %% 我们关心函数调用
 776            dbg:tpl(ftp, [{'_', [], [{return_trace}]}]), %%以及返回值
 777            dbg:tpl(ftp_response, [{'_', [], [{return_trace}]}]),
 778            dbg:tpl(ftp_progress, [{'_', [], [{return_trace}]}]);
 779        debug ->
 780            dbg:tracer(),
 781            dbg:p(all, [call]),
 782            dbg:tp(ftp, [{'_', [], [{return_trace}]}]),
 783            dbg:tp(ftp_response, [{'_', [], [{return_trace}]}]),
 784            dbg:tp(ftp_progress, [{'_', [], [{return_trace}]}]);
 785        _ ->
 786            %% Keep silent                                                                                                                                                                                 
 787            ok
 788    end,

我们可以在启动参数里面加上debug标志, 在需要的时候打开这些诊断功能!

现在我们演示下,代码片段从inets userguide来的, 用户名密码不用试验了, 我不会告诉你的, 呵呵:

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

Eshell V5.8  (abort with ^G)
1> inets:start().  
ok
2> {ok,Pid} = inets:start(ftpc, [{host,"ftp.yufeng.info"},{debug,debug}])
2> .
(<0.45.0>) call ftp:handle_call({<0.31.0>,
 {open,ip_comm,
       [{host,"ftp.yufeng.info"},
        {progress,ignore},
        {timeout,60000},
        {ipfamily,inet},
        {port,21},
        {mode,passive}]}},{<0.31.0>,#Ref<0.0.0.45>},{state,undefined,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,undefined,undefined,inet,ignore})
(<0.45.0>) call ftp_progress:start_link(ignore)
(<0.45.0>) returned from ftp_progress:start_link/1 -> ignore
(<0.45.0>) returned from ftp:handle_call/3 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.45>},
                                                open,inet,ignore},
                                               59493}
(<0.45.0>) call ftp:handle_info({tcp,#Port<0.1086>,
     <<"220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------\r\n220-You are user number 7 of 1000 allowed.\r\n220-Local time is now 02:33. Server port: 21.\r\n220-IPv6 connections are also welcome on this server.\r\n220 You will be disconnected after 15 minutes of inactivity.\r\n">>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.45>},
       open,inet,ignore})
(<0.45.0>) call ftp_response:parse_lines(<<"220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------\r\n220-You are user number 7 of 1000 allowed.\r\n220-Local time is now 02:33. Server port: 21.\r\n220-IPv6 connections are also welcome on this server.\r\n220 You will be disconnected after 15 minutes of inactivity.\r\n">>,[],start)
(<0.45.0>) returned from ftp_response:parse_lines/3 -> {ok,
                                                        "220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------\r\n220-You are user number 7 of 1000 allowed.\r\n220-Local time is now 02:33. Server port: 21.\r\n220-IPv6 connections are also welcome on this server.\r\n220 You will be disconnected after 15 minutes of inactivity.\r\n",
                                                        <<>>}
(<0.45.0>) call ftp_response:interpret("220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------\r\n220-You are user number 7 of 1000 allowed.\r\n220-Local time is now 02:33. Server port: 21.\r\n220-IPv6 connections are also welcome on this server.\r\n220 You will be disconnected after 15 minutes of inactivity.\r\n")
{ok,<0.45.0>}
(<0.45.0>) returned from ftp_response:interpret/1 -> {pos_compl,
                                                      "---------- Welcome to Pure-FTPd [privsep] [TLS] ----------\r\n220-You are user number 7 of 1000 allowed.\r\n220-Local time is now 02:33. Server port: 21.\r\n220-IPv6 connections are also welcome on this server.\r\n220 You will be disconnected after 15 minutes of inactivity.\r\n"}
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,undefined,undefined,
                                                inet,ignore}}
3> ftp:user(Pid, "username", "password").
(<0.31.0>) call ftp:user(<0.45.0>,"username","password")
(<0.45.0>) call ftp:handle_call({<0.31.0>,{user,"username","password"}},{<0.31.0>,#Ref<0.0.0.64>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,undefined,undefined,inet,ignore})
(<0.45.0>) returned from ftp:handle_call/3 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.64>},
                                                {handle_user,"password",[]},
                                                inet,ignore}}
(<0.45.0>) call ftp:handle_info({tcp,#Port<0.1086>,<<"331 User yufengin OK. Password required\r\n">>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.64>},
       {handle_user,"password",[]},
       inet,ignore})
(<0.45.0>) call ftp_response:parse_lines(<<"331 User yufengin OK. Password required\r\n">>,[],start)
(<0.45.0>) returned from ftp_response:parse_lines/3 -> {ok,
                                                        "331 User yufengin OK. Password required\r\n",
                                                        <<>>}
(<0.45.0>) call ftp_response:interpret("331 User yufengin OK. Password required\r\n")
(<0.45.0>) returned from ftp_response:interpret/1 -> {pos_interm,
                                                      " User yufengin OK. Password required\r\n"}
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.64>},
                                                {handle_user_passwd,[]},
                                                inet,ignore}}
(<0.45.0>) call ftp:handle_info({tcp,#Port<0.1086>,
     <<"230-User yufengin has group access to:  yufengin  \r\n230 OK. Current restricted directory is /\r\n">>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.64>},
       {handle_user_passwd,[]},
       inet,ignore})
(<0.45.0>) call ftp_response:parse_lines(<<"230-User yufengin has group access to:  yufengin  \r\n230 OK. Current restricted directory is /\r\n">>,[],start)
(<0.45.0>) returned from ftp_response:parse_lines/3 -> {ok,
                                                        "230-User yufengin has group access to:  yufengin  \r\n230 OK. Current restricted directory is /\r\n",
                                                        <<>>}
(<0.45.0>) call ftp_response:interpret("230-User yufengin has group access to:  yufengin  \r\n230 OK. Current restricted directory is /\r\n")
ok
(<0.45.0>) returned from ftp_response:interpret/1 -> {pos_compl,
                                                      "-User yufengin has group access to:  yufengin  \r\n230 OK. Current restricted directory is /\r\n"}
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,undefined,undefined,
                                                inet,ignore}}
(<0.31.0>) returned from ftp:user/3 -> ok
4> 
4>  ftp:pwd(Pid).
(<0.31.0>) call ftp:pwd(<0.45.0>)
(<0.45.0>) call ftp:handle_call({<0.31.0>,pwd},{<0.31.0>,#Ref<0.0.0.84>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,undefined,undefined,inet,ignore})
(<0.45.0>) returned from ftp:handle_call/3 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.84>},
                                                pwd,inet,ignore}}
(<0.45.0>) call ftp:handle_info({tcp,#Port<0.1086>,<<"257 \"/\" is your current location\r\n">>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.84>},
       pwd,inet,ignore})
(<0.45.0>) call ftp_response:parse_lines(<<"257 \"/\" is your current location\r\n">>,[],start)
(<0.45.0>) returned from ftp_response:parse_lines/3 -> {ok,
                                                        "257 \"/\" is your current location\r\n",
                                                        <<>>}
(<0.45.0>) call ftp_response:interpret("257 \"/\" is your current location\r\n")
{ok,"/"}
(<0.45.0>) returned from ftp_response:interpret/1 -> {pos_compl,
                                                      " \"/\" is your current location\r\n"}
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,undefined,undefined,
                                                inet,ignore}}
(<0.31.0>) returned from ftp:pwd/1 -> {ok,"/"}
7> ftp:recv(Pid, "favicon.ico").
(<0.31.0>) call ftp:recv(<0.45.0>,"favicon.ico")
(<0.45.0>) call ftp:handle_call({<0.31.0>,{recv,"favicon.ico","favicon.ico"}},{<0.31.0>,#Ref<0.0.0.120>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.112>},
       undefined,inet,ignore})
(<0.45.0>) returned from ftp:handle_call/3 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.120>},
                                                {setup_data_connection,
                                                 {recv_file,"favicon.ico",
                                                  {file_descriptor,prim_file,
                                                   {#Port<0.1087>,9}}}},
                                                inet,ignore}}
(<0.45.0>) call ftp:handle_info({tcp,#Port<0.1086>,
     <<"227 Entering Passive Mode (74,220,215,202,156,59)\r\n">>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,
    passive,60000,<<>>,
    {<<>>,[],start},
    <0.31.0>,
    {<0.31.0>,#Ref<0.0.0.120>},
    {setup_data_connection,
        {recv_file,"favicon.ico",
            {file_descriptor,prim_file,{#Port<0.1087>,9}}}},
    inet,ignore})
(<0.45.0>) call ftp_response:parse_lines(<<"227 Entering Passive Mode (74,220,215,202,156,59)\r\n">>,[],start)
(<0.45.0>) returned from ftp_response:parse_lines/3 -> {ok,
                                                        "227 Entering Passive Mode (74,220,215,202,156,59)\r\n",
                                                        <<>>}
(<0.45.0>) call ftp_response:interpret("227 Entering Passive Mode (74,220,215,202,156,59)\r\n")
(<0.45.0>) returned from ftp_response:interpret/1 -> {pos_compl,
                                                      " Entering Passive Mode (74,220,215,202,156,59)\r\n"}
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                #Port<0.1093>,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.120>},
                                                {recv_file,
                                                 {file_descriptor,prim_file,
                                                  {#Port<0.1087>,9}}},
                                                inet,ignore}}
(<0.45.0>) call ftp:handle_info({tcp,#Port<0.1086>,<<"150 Accepted data connection\r\n">>},{state,#Port<0.1086>,#Port<0.1093>,false,"/root",ftp_server_default,false,
       passive,60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.120>},
       {recv_file,{file_descriptor,prim_file,{#Port<0.1087>,9}}},
       inet,ignore})
(<0.45.0>) call ftp_response:parse_lines(<<"150 Accepted data connection\r\n">>,[],start)
(<0.45.0>) returned from ftp_response:parse_lines/3 -> {ok,
                                                        "150 Accepted data connection\r\n",
                                                        <<>>}
(<0.45.0>) call ftp_response:interpret("150 Accepted data connection\r\n")
(<0.45.0>) returned from ftp_response:interpret/1 -> {pos_prel,
                                                      " Accepted data connection\r\n"}
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                #Port<0.1093>,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.120>},
                                                {recv_file,
                                                 {file_descriptor,prim_file,
                                                  {#Port<0.1087>,9}}},
                                                inet,ignore}}
ok
8> (<0.45.0>) call ftp:handle_info({tcp,#Port<0.1093>,
     <<71,73,70,56,57,97,1,0,1,0,128,0,0,255,255,255,255,255,255,33,249,4,1,7,
       0,1,0,44,0,0,0,0,1,0,1,0,0,2,2,76,1,0,59>>},{state,#Port<0.1086>,#Port<0.1093>,false,"/root",ftp_server_default,false,
       passive,60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.120>},
       {recv_file,{file_descriptor,prim_file,{#Port<0.1087>,9}}},
       inet,ignore})
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                #Port<0.1093>,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.120>},
                                                {recv_file,
                                                 {file_descriptor,prim_file,
                                                  {#Port<0.1087>,9}}},
                                                inet,ignore}}
(<0.45.0>) call ftp:handle_info({tcp_closed,#Port<0.1093>},{state,#Port<0.1086>,#Port<0.1093>,false,"/root",ftp_server_default,false,
       passive,60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.120>},
       {recv_file,{file_descriptor,prim_file,{#Port<0.1087>,9}}},
       inet,ignore})
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,
                                                {<0.31.0>,#Ref<0.0.0.120>},
                                                {recv_file,
                                                 {file_descriptor,prim_file,
                                                  {#Port<0.1087>,9}}},
                                                inet,ignore}}
(<0.45.0>) call ftp:handle_info({tcp,#Port<0.1086>,
     <<"226-File successfully transferred\r\n226 0.020 seconds (measured here), 2.07 Kbytes per second\r\n">>},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,
       {<0.31.0>,#Ref<0.0.0.120>},
       {recv_file,{file_descriptor,prim_file,{#Port<0.1087>,9}}},
       inet,ignore})
(<0.45.0>) call ftp_response:parse_lines(<<"226-File successfully transferred\r\n226 0.020 seconds (measured here), 2.07 Kbytes per second\r\n">>,[],start)
(<0.45.0>) returned from ftp_response:parse_lines/3 -> {ok,
                                                        "226-File successfully transferred\r\n226 0.020 seconds (measured here), 2.07 Kbytes per second\r\n",
                                                        <<>>}
(<0.45.0>) call ftp_response:interpret("226-File successfully transferred\r\n226 0.020 seconds (measured here), 2.07 Kbytes per second\r\n")
(<0.45.0>) returned from ftp_response:interpret/1 -> {pos_compl,
                                                      "-File successfully transferred\r\n226 0.020 seconds (measured here), 2.07 Kbytes per second\r\n"}
(<0.45.0>) returned from ftp:handle_info/2 -> {noreply,
                                               {state,#Port<0.1086>,
                                                undefined,false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,undefined,undefined,
                                                inet,ignore}}
(<0.31.0>) returned from ftp:recv/2 -> ok

8> inets:stop(ftpc, Pid).
ok
9> (<0.31.0>) call ftp:stop_service(<0.45.0>)
(<0.31.0>) returned from ftp:stop_service/1 -> ok
(<0.45.0>) call ftp:handle_cast({<0.31.0>,close},{state,#Port<0.1086>,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,undefined,undefined,inet,ignore})
(<0.45.0>) returned from ftp:handle_cast/2 -> {stop,normal,
                                               {state,undefined,undefined,
                                                false,"/root",
                                                ftp_server_default,false,
                                                passive,60000,<<>>,
                                                {<<>>,[],start},
                                                <0.31.0>,undefined,undefined,
                                                inet,ignore}}
(<0.45.0>) call ftp:terminate(normal,{state,undefined,undefined,false,"/root",ftp_server_default,false,passive,
       60000,<<>>,
       {<<>>,[],start},
       <0.31.0>,undefined,undefined,inet,ignore})
(<0.45.0>) returned from ftp:terminate/2 -> ok
9> h().      
1: inets:start()
-> ok
2: {ok,Pid} =
       inets:start(ftpc, [{host,"ftp.yufeng.info"},{debug,debug}])
-> {ok,<0.45.0>}
3: ftp:user(Pid, "username", "password")
-> ok
4: ftp:pwd(Pid)
-> {ok,"/"}
5: ftp:cd(Pid, "public_html")
-> ok
6: ftp:lpwd(Pid)
-> {ok,"/root"}
7: ftp:recv(Pid, "favicon.ico")
-> ok
8: inets:stop(ftpc, Pid)
-> ok

Bingo! 我们非常的清楚了看到了整个系统交互的流程. 不废吹灰之力.

erlang的trace机制非常强大, 在dbg, ttb模块的配合下, 可以非常清楚的了解系统的运作, 排错, 和调优. 但是有个对于做网络程序重要的功能被忽视了, 没有写到文档. 那就是trace ports消息.
我们的gen_tcp,file都是port实现的, 那么了解这么模块的运作其实就是要跟踪系统对ports的打开, 关闭, 读写操作.
好吧,上代码的时间了.
由于是未公开的功能, 所以dbg模块默认也是没启用这个功能的.我们patch下:
lib/runtime_tools/src/dbg.erl

1128all() ->
1129    [send,'receive',call,procs,garbage_collection,running,
1130     set_on_spawn,set_on_first_spawn,set_on_link,set_on_first_link,
1131     timestamp,arity,return_to, ports].  %%添加ports

重新编译, 安装.

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

Eshell V5.8  (abort with ^G)
1> dbg:tracer().
{ok,<0.33.0>}
2> dbg:p(all, [ports]).
{ok,[{matched,nonode@nohost,0}]}
3> ls().    
(<0.3.0>) open #Port<0.522> efile
(#Port<0.522>) closed normal
(<0.3.0>) open #Port<0.523> efile
(#Port<0.523>) closed normal
(<0.3.0>) open #Port<0.524> efile
(#Port<0.524>) closed normal
(<0.3.0>) open #Port<0.525> efile
(#Port<0.525>) closed normal
(<0.3.0>) open #Port<0.526> efile
(#Port<0.526>) closed normal
.git                       .gitignore                 
.mailmap                   AUTHORS                    

ok
4> os:cmd("ls").
(<0.40.0>) open #Port<0.527> '/bin/sh -s unix:cmd 2>&1'
(#Port<0.527>) closed {}
"aclocal.m4\nAUTHORS\n"
(<0.3.0>) open #Port<0.522> efile
(#Port<0.522>) closed normal
(<0.3.0>) open #Port<0.523> efile
(#Port<0.523>) closed normal
(<0.3.0>) open #Port<0.524> efile
(#Port<0.524>) closed normal
(<0.3.0>) open #Port<0.525> efile
(#Port<0.525>) closed normal
(<0.3.0>) open #Port<0.526> efile
(#Port<0.526>) closed normal
5> {ok, F} = file:open("AUTHORS", [read]).
(<0.39.0>) open #Port<0.527> efile
{ok,<0.39.0>}
6> file:read(F, 1024).
{ok,"AUTHORS\n\n  Contributions - improvements, fixes, new features - from developers\n  make the Erlang 'Open Source' project a success. To give credit\n  where it's due, we've added a file called AUTHORS to each\n  application sub-directory with a list of everyone who has contributed\n  It might also contain the names of the original authors at Ericsson.\n\n  Speaking of original authors, we don't want to forget all the people\n  working full time with Erlang and OTP. So, thanks to everyone\n  working with Erlang at the OTP group, the Computer Science\n  Laboratory and the Software Architecture Laboratory.\n\n"} 
7> file:close(F).
ok
8> (#Port<0.527>) closed normal

这么简单的我们透过这个功能可以了解到ports的运作(打开, 关闭)了,多谢otp开发组.

原文地址: http://old.nabble.com/Linear-scaling-on-multicore-to28176394.html#a28176394

这个帖子希望能给写IO密集应用的人以信心, erlvideo的代码质量其实还有很大的上升空间.

从 Nabble – Erlang 作者：Max Lapshin-2
Hi. I’ve made benchmarks of erlyvideo yesterday. Largest load was 1800
clients, totally consuming about 700 MBit live
video stream from one server. Erlyvideo used 450% of CPU for it (5 cores).

I want to thank all Erlang team, for such wonderful platform: I’ve got
full linear scaling on multicore computer without any problems,
from 150 up to 1800 clients, it took 0,25% CPU per client and not more.

Here is graphic of load: http://erlyvideo.org/erlyvideo-load.png

Thank you!

________________________________________________________________
erlang-questions (at) erlang.org mailing list.
See http://www.erlang.org/faq.html
To unsubscribe; mailto:erlang-questions-unsubscribe@…

From forum: Erlang Questions