系统技术非业余研究

在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!