系统技术非业余研究

我们开发好了一个软件的时候,通常是经过严格测试的,才分发给用户使用, 但是即使这样也不能保证用户的环境和我们的相同, 我们的软件还是会失败的. 问题是如何诊断这些问题.
通常的做法是写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

gen*都需要callback模块提供一个init模块, 在这个模块里面做相应的初始化操作.

我们以gen_server为例子. 当我们调用gen_server:start_link的时候,  底层会委托proc_lib来启动新的进程同时调用我们的init函数进行初始化.  同时gen系列会同步等待新进程初始化完毕, 才接着往下执行.

我们看下文档:

gen_server:start_link(ServerName, Module, Args, Options) -> Result
The gen_server process calls Module:init/1 to initialize. To ensure a synchronized start-up procedure, start_link/3,4 does not return until Module:init/1 has returned.

我们会经常误解这个行为, 以为start是马上返回的, otp团队之前也修正httpc的一个这类问题的bug.

所以我们在init的时候, 尽可能的做些简单的工作. 如果需要做费时的操作, 那么可以先让一条消息, 放到消息队列去, 让init马上返回. 这时候兵分二路, 调用进程可以继续往下执行, 费时操作也在稍后被调用.

而且gen*系列一旦启动起来, 如果该进程不幸发生意外崩溃,  proc_lib会负责记录当时的现场和原因,  非常有助于诊断.

我们演示下这个问题:

root@ubuntu:~# cat tg.erl

-module(tg).

-behaviour(gen_server).

%% API
-export([start/0]).

%% gen_server callbacks
-export([init/1, handle_call/3, handle_cast/2, handle_info/2,
terminate/2, code_change/3]).

-record(state, {}).
-define(SERVER, ?MODULE).

start() ->
gen_server:start_link({local, ?SERVER}, ?MODULE, [], []).

init([]) ->

io:format("init pid ~p~n", [self()]),

%% sleep
receive
after 3000 ->
cont
end,

erlang:send_after(0, self(), crash_me),

{ok, #state{}}.

handle_call(_Request, _From, State) ->
Reply = ok,
{reply, Reply, State}.

handle_cast(_Msg, State) ->
{noreply, State}.

handle_info(crash_me, State) ->
% do some hard work

% crash me
exit(crash_me),
{noreply, State};

handle_info(_Info, State) ->
{noreply, State}.

terminate(_Reason, _State) ->
ok.

code_change(_OldVsn, State, _Extra) ->
{ok, State}.

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> self().
<0.36.0>
2> timer:tc(tg, start, []).
init pid <0.34.0>
{3003583,{ok,<0.34.0>}}
2>
=ERROR REPORT==== 8-Apr-2010::16:20:09 ===
** Generic server tg terminating
** Last message in was crash_me
** When Server state == {state}
** Reason for termination ==
** crash_me
** exception error: crash_me
2>

1. 我们个tg:start启动了3003毫秒, 证明这是同步调用.

2. init是在新进程里面执行的
3. 我们的费时间操作用erlang:send_after发起
4. 一旦发生crash我们有记录在案.

收工!

很多同学在使用erlang的过程中, 碰到了很奇怪的问题, 后来查明都是文件句柄不够用了, 因为系统默认的是每个进程1024. 所以我们有必要在程序运行的时候, 了解这些信息, 以便诊断和预警.
下面的这个程序就演示了这个如何查看节点的可用句柄数目和已用句柄数的功能.

首先确保你已经安装了lsof, 我的系统是ubuntu可以这样安装.

root@ubuntu:~# apt-get -y install lsof   

root@ubuntu:~# cat fd.erl

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

get_total_fd_ulimit() ->
    {MaxFds, _} = string:to_integer(os:cmd("ulimit -n")),
    MaxFds.

get_total_fd() -> get_total_fd(os:type()).

get_total_fd({unix, Os})
  when Os =:= linux orelse
       Os =:= darwin orelse
       Os =:= freebsd orelse Os =:= sunos ->
    get_total_fd_ulimit();
get_total_fd(_) -> unknown.

get_used_fd_lsof() ->
    Lsof = os:cmd("lsof -d \"0-9999999\" -lna -p " ++
                  os:getpid()),
    string:words(Lsof, $\n).

get_used_fd() -> get_used_fd(os:type()).

get_used_fd({unix, Os})
  when Os =:= linux orelse
       Os =:= darwin orelse Os =:= freebsd ->
    get_used_fd_lsof();
get_used_fd(_) -> unknown.

start()->
    io:format("total fd: ~p~n"
              "used fd: ~p~n", [get_total_fd(), get_used_fd()]),
    halt(0).

root@ubuntu:~# erlc fd.erl
root@ubuntu:~# ulimit -n 1024
root@ubuntu:~# erl -noshell -s fd      
total fd: 1024
used fd: 10
root@ubuntu:~# ulimit -n 10240   
root@ubuntu:~# erl -noshell -s fd
total fd: 10240
used fd: 10
root@ubuntu:~# 

收工!

erts_debug:get_internal_state是用来获取Erlang运行期内部信息的主要手段. 但是这个功能是用来给开发人员或者说需要了解系统内部细节的场合, 比如说系统调优.
在R13B04可以使用的选项有:
1. reds_left
2. node_and_dist_references
3. monitoring_nodes
4. next_pid
5. next_port
6. ‘DbTable_words’
7. check_io_debug
8. process_info_args
9. processes
10. processes_bif_info
11. max_atom_out_cache_index
12. nbalance
13. available_internal_state
14. force_heap_frags
15. {process_status, Pid}
16. {link_list, Pid} 或者 {link_list, Port} 或者 {link_list, Nodename}
17. {monitor_list, Pid} 或者 {monitor_list, Nodename}
18. {channel_number, Sysname}
19. {have_pending_exit, Pid}
20. {binary_info, Binary}
21. {dist_port, Sysname}
22. {atom_out_cache_index, Atom}
23. {fake_scheduler_bindings, How} How=spread | processor_spread | thread_spread | default_bind | no_node_processor_spread | no_node_thread_spread | no_spread | unbound

使用此功能的前提是先用erts_debug:set_internal_state(available_internal_state, true). 否者调用get_internal_state会提示失败.
我们演示下:

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

Eshell V5.8  (abort with ^G)
(x@ubuntu)1> erts_debug:get_internal_state(check_io_debug). 
** exception error: undefined function erts_debug:get_internal_state/1
(x@ubuntu)2> erts_debug:set_internal_state(available_internal_state, true).
false
=ERROR REPORT==== 7-Apr-2010::14:40:41 ===
Process <0.38.0> on node 'x@ubuntu' enabled access to the emulator internal state.
NOTE: This is an erts internal test feature and should *only* be used by OTP test-suites.
(x@ubuntu)3> erts_debug:get_internal_state(check_io_debug). 
--- fds in pollset --------------------------------------
fd=0 type=chr driver_select ev=IN  inport=#Port<0.294> inname=tty_sl -c -e indrv=tty_sl 
fd=3 type=fifo internal ep_ev=IN
fd=4 type=fifo internal 
fd=7 type=sock driver_select ev=IN  inport=#Port<0.62> inname=tcp_inet indrv=tcp_inet 
fd=8 type=sock driver_select ev=IN  inport=#Port<0.65> inname=tcp_inet indrv=tcp_inet 
fd=9 type=fifo driver_select ev=IN  inport=#Port<0.486> inname=inet_gethost 4  indrv=spawn 
fd=10 type=sock driver_select ev=IN  inport=#Port<0.492> inname=tcp_inet indrv=tcp_inet 
fd=11 type=sock driver_select ev=IN  inport=#Port<0.495> inname=tcp_inet indrv=tcp_inet 

used fds=6
internal fds=2
---------------------------------------------------------
0
(x@ubuntu)4>  erts_debug:get_internal_state({process_status, self()}).
running

List Comprehensions
List comprehensions are a feature of many modern functional programming languages. Subject to certain rules, they provide a succinct notation for generating elements in a list.
List comprehensions are analogous to set comprehensions in Zermelo-Frankel set theory and are called ZF expressions in Miranda. They are analogous to the setof and findall predicates in Prolog.

List comprehensions are written with the following syntax:

[Expr || Qualifier1,…,QualifierN]

Expr is an arbitrary expression, and each Qualifier is either a generator or a filter.

* A generator is written as:
Pattern <- ListExpr. ListExpr must be an expression which evaluates to a list of terms. * A bit string generator is written as: BitstringPattern <= BitStringExpr. BitStringExpr must be an expression which evaluates to a bitstring. * A filter is an expression which evaluates to true or false.

但是从R13B以后lc是可以不要generator的, 只要filter也可以.

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> Nums = [1,2,3], Nouns = [shoe,box,tape], Verbs = [].
[]
2> [Nums || Nums =/= []] ++ [Nouns || Nouns =/= []] ++ [Verbs || Verbs
=/= []].
[[1,2,3],[shoe,box,tape]] 

这样的话你就可以写类似这样的代码:

Cond = 2,
[io:format("hello~n", []) || Cond =/=1].

免得用if 或者case语句写, 整个代码显得更清爽.