tsung 压力测 试遇到的几个问题

   

   注册 用户 超过  130000 178864
    设备              156584 
1.               
   测试关于“汉字”更新数据
后台抛出 =INFO REPORT==== 2010-10-25 18:07:47 ===
D(<0.1906.0>:ejabberd_odbc:416) : MySQL, Send query
["UPDATE vendors SET vendorname='",[20013],"' WHERE vendorid='","37","';"]
   
   
  

   =INFO REPORT==== 2010-10-25 18:07:52 ===
D(<0.1906.0>:ejabberd_odbc:416) : MySQL, Send query
"rollback;"
  

   2.单个 虚拟机 测试（ <client host="client-3.langzhelabdns.com" use_controller_vm="true" maxusers="60000"/>
）
   
    解决方法：
   
   以下问题 修改ulimit -n 102400参数解决

INFO REPORT==== 1-Nov-2010::13:46:29 ===
         ts_launcher:(5:<0.84.0>) Activate launcher (60000 users) in 10002 msec

=INFO REPORT==== 1-Nov-2010::13:49:47 ===
           ts_client:(3:<0.12537.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: etimedout

=INFO REPORT==== 1-Nov-2010::13:49:47 ===
           ts_client:(3:<0.12536.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: etimedout

=INFO REPORT==== 1-Nov-2010::13:49:47 ===
           ts_client:(3:<0.12535.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: etimedout


日志－－－：






           ts_client:(3:<0.6577.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: system_limit

=INFO REPORT==== 1-Nov-2010::10:35:44 ===
           ts_client:(3:<0.4203.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: system_limit

=INFO REPORT==== 1-Nov-2010::10:35:44 ===
           ts_client:(5:<0.4203.0>) Pending transactions: [{tr_device_register,
                                                            {1288,578941,
                                                             906458}}], compute transaction time

=INFO REPORT==== 1-Nov-2010::10:35:44 ===
           ts_client:(3:<0.4378.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: system_limit

=INFO REPORT==== 1-Nov-2010::10:35:44 ===
           ts_client:(5:<0.4378.0>) Pending transactions: [{tr_device_register,
                                                            {1288,578941,
                                                             906438}}], compute transaction time

=INFO REPORT==== 1-Nov-2010::10:35:44 ===
           ts_client:(3:<0.5622.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: system_limit

=INFO REPORT==== 1-Nov-2010::10:35:44 ===
           ts_client:(3:<0.4033.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: system_limit

=INFO REPORT==== 1-Nov-2010::10:35:44 ===






Error: econnreset
 
           ts_client:(3:<0.32258.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: econnrefused

=INFO REPORT==== 1-Nov-2010::10:41:03 ===
           ts_client:(3:<0.27051.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: econnrefused

=INFO REPORT==== 1-Nov-2010::10:41:03 ===
           ts_client:(5:<0.27051.0>) Pending transactions: [{tr_user_register,
                                                             {1288,579203,
                                                              9045}}], compute transaction time

=INFO REPORT==== 1-Nov-2010::10:41:03 ===
           ts_client:(3:<0.31393.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: econnrefused

3. ------------------------------------------------
 根据上面出现的情况 调整ulimit参数后，tsung日志出现  etimedout （ssh验证 tsung监听 ）会出现此问题
参见 http://www.javaeye.com/topic/573238部分解释

=INFO REPORT==== 1-Nov-2010::13:49:47 ===
           ts_client:(3:<0.12532.0>) (Re)connect from 0.0.0.0 to testrsa.langzhelabdns.com:5280, Error: etimedout
   
    解决方
   
   法 配置ssh 信任

4. －－－－死锁 ------------------ -------------代码中出现了for update引起 去掉就OK了-- ---------------
 =INFO REPORT==== 2010-11-01 10:22:06 ===
 15403 D(<0.517.0>:ejabberd_http:323) : ["user","register"] matches ["user",
 15404                                                               "register"]
 15405 
 15406 =INFO REPORT==== 2010-11-01 10:22:06 ===
 15407 D(<0.259.0>:ejabberd_odbc:420) : MySQL, Send query
 15408 ["SELECT vendorid FROM vendors WHERE vendorname = '","test","' FOR UPDATE;"]
 15409 
 15410 
 15411 =INFO REPORT==== 2010-11-01 10:22:06 ===
 15412 D(<0.247.0>:ejabberd_odbc:420) : MySQL, Send query
 15413 ["SELECT vendorid FROM vendors WHERE vendorname = '","test","' FOR UPDATE;"]
 15414 
 15415 
 15416 =INFO REPORT==== 2010-11-01 10:22:06 ===
 15417 D(<0.437.0>:mod_langzhe_device_register:71) : transactionResult = {aborted,
 15418                                                                 {{badmatch,
 15419                                                                   {error,
 15420                                                                    "#40001Deadlock found when trying to get lock; try restarting transaction"}},
 15421                                                                  [{mod_langzhe_basic,
 15422                                                                    add_device_type,
 15423                                                                    2},
 15424                                                                   {mod_langzhe_device_register,
 15425                                                                    '-process/2-fun-0-',
 15426                                                                    7},
 15427                                                                   {ejabberd_odbc,
 15428                                                                    outer_transaction,
 15429                                                                    3},
 15430                                                                   {ejabberd_odbc,
 15431                                                                    session_established,
 15432                                                                    3},
 15433                                                                   {p1_fsm,
 15434                                                                    handle_msg,
 15435                                                                    10},
                             

5.－－－－－－－－－－－ 注册用户 40080－  －－－－－－－－－－－－－
Mon Nov  1 16:05:19 2010
Slogan: eheap_alloc: Cannot allocate 729810240 bytes of memory (of type "heap").
System version: Erlang R13B03 (erts-5.7.4) [source] [smp:2:2] [rq:2] [async-threads:0] [kernel-poll:true]
Compiled: Fri Oct 15 14:49:18 2010
Atoms: 15554
=memory
total: 1802636424
processes: 1646297908
processes_used: 1645947788
system: 156338516
atom: 710173
atom_used: 696317
binary: 235232
code: 6574357
ets: 5148228
=hash_table:atom_tab
＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝＝
Mon Nov  1 15:52:53 2010
Slogan: eheap_alloc: Cannot allocate 912262800 bytes of memory (of type "heap").
System version: Erlang R13B03 (erts-5.7.4) [source] [smp:2:2] [rq:2] [async-threads:0] [kernel-poll:true]
Compiled: Fri Oct 15 14:49:18 2010
Atoms: 15554
=memory
total: 2105409384
processes: 2059069028
processes_used: 2058770452
system: 46340356
atom: 710173
atom_used: 696317
binary: 207192
code: 6574357
ets: 5148596
=hash_table:atom_tab
size: 9643
used: 7694
objs: 15554
depth: 8
-----------------------------------------
=erl_crash_dump:0.1注册用户数 32874     600s 300/s  服务器抛出 错误时 物理内存 被占用81％ （2G内存）
912262800/1024/1024 > 0.19*2*1024(870>389 显然 是内存不足)

Mon Nov  1 16:30:25 2010
Slogan: eheap_alloc: Cannot allocate 912262800 bytes of memory (of type "heap").
System version: Erlang R13B03 (erts-5.7.4) [source] [smp:2:2] [rq:2] [async-threads:0] [kernel-poll:true]
Compiled: Fri Oct 15 14:49:18 2010
Atoms: 15554
=memory
total: 2238866320
processes: 2077803940
processes_used: 2077676852
system: 161062380
atom: 710173
atom_used: 696317
binary: 222712
code: 6574357
ets: 5148340
=hash_table:atom_tab
size: 9643
used: 7694
objs: 15554
depth: 8
   
    解决方法
   
   分析后发现是日志级别引起，设为info就OK 
六、－－－－－－－－－－－FSM limit reached (<0.255.0>): {max_queue,1003}--------------------------------------------
=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.27300.0>:ejabberd_http:137) : started: {gen_tcp,#Port<0.30873>}

=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.384.0>:ejabberd_listener:234) : (#Port<0.30874>) Accepted connection {{192,168,0,223},40244} -> {{192,168,0,223},5280}

=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.27301.0>:ejabberd_http:137) : started: {gen_tcp,#Port<0.30874>}

=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.384.0>:ejabberd_listener:234) : (#Port<0.30875>) Accepted connection {{192,168,0,223},54723} -> {{192,168,0,223},5280}

=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.27302.0>:ejabberd_http:137) : started: {gen_tcp,#Port<0.30875>}

=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.384.0>:ejabberd_listener:234) : (#Port<0.30876>) Accepted connection {{192,168,0,223},47419} -> {{192,168,0,223},5280}

=ERROR REPORT==== 2010-11-01 20:30:30 ===
FSM limit reached (<0.255.0>): {max_queue,1003}

=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.257.0>:ejabberd_odbc:526) : Closing connection #Port<0.3650>: ok


=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.27303.0>:ejabberd_http:137) : started: {gen_tcp,#Port<0.30876>}

=INFO REPORT==== 2010-11-01 20:30:30 ===
I(<0.384.0>:ejabberd_listener:234) : (#Port<0.30877>) Accepted connection {{192,168,0,223},60273} -> {{192,168,0,223},5280}

=INFO REPORT==== 2010-11-01 20:30:33 ===
I(<0.27307.0>:ejabberd_http:137) : started: {gen_tcp,#Port<0.30877>}

=INFO REPORT==== 2010-11-01 20:30:34 ===
I(<0.384.0>:ejabberd_listener:234) : (#Port<0.30878>) Accepted connectio       
解决方法 参见 :
   
    http://langzhe.javaeye.com/admin/blogs/801942
   
   

   七、－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－
=INFO REPORT==== 2010-11-02 08:57:24 ===
I(<0.384.0>:ejabberd_listener:246) : (#Port<0.4265>) Failed TCP accept: emfile
解决方法: vi /etc/ejabberd/ejabberdctl.cfg 修改
ERL_PROCESSES=250000
ERL_MAX_PORTS=320000
参数和ulimit -n 参数
enfile问题参考
   
    http://www.netadmintools.com/art295.html
   
   八、－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－
方法1 修改maxusers参数<client host="client-3.langzhelabdns.com" use_controller_vm="true" maxusers="6000000"/>
方法2 修改use_controller_vm参数 <client host="client-3.langzhelabdns.com" use_controller_vm="faluse"/>
"Maximum number of concurrent users in a single VM reached and 'use_controller_vm' is true, can't start new beam !!! Check 'maxusers' value in <client> configuration.~n"

九、－－－－－－－－－－－ID 越过－－－没有生成 vendordid 为64的记录－－－－－－－－－－－－－－－－－－－－－－
 select * from vendors where vendorid like'6_' order by vendorid;
+----------+------------+
| vendorid | vendorname |
+----------+------------+
|       60 | test160    |
|       61 | test161    |
|       62 | test162    |
|       63 | test163    |
|       65 | test164    |‪
|       66 | test165    |
|       67 | test166    |
|       68 | test167    |
|       69 | test168    |
+----------+------------+

 157 | test1157   |
|      159 | test1158   |
|      160 | test1159 

＝＝＝＝＝＝下面两个问题还没有解决＝＝＝＝＝＝＝＝＝＝＝＝
十一、－－－－－－－－－－－－－－－－－－－－－－－－－－
=INFO REPORT==== 2010-11-03 17:42:19 ===
I(<0.20211.0>:ejabberd_http:137) : started: {gen_tcp,#Port<0.23590>}

=ERROR REPORT==== 2010-11-03 17:42:19 ===
** State machine <0.235.0> terminating 
** Last message in was {'$gen_sync_event',
                           {<0.7013.0>,#Ref<0.0.0.125463>},
                           {sql_cmd,
                               {sql_query,
                                   ["SELECT keyt FROM langzhe_vendor_key WHERE vendor = '",
                                    "test","' and version = '","1","';"]}}}
** When State == session_established
**      Data  == {state,<0.236.0>,mysql,30000,"testrsa.langzhelabdns.com",
                        1000000000000,
                        {0,{[],[]}}}
** Reason for termination = 
** timeout

==> ejabberd.log <==
                           {sql_cmd,
                               {sql_query,
                                   ["SELECT keyt FROM langzhe_vendor_key WHERE vendor = '",
                                    "test","' and version = '","1","';"]}}}
** When State == session_established
**      Data  == {state,<0.236.0>,mysql,30000,"testrsa.langzhelabdns.com",
                        1000000000000,
                        {0,{[],[]}}}
** Reason for termination = 
** timeout

十二、－－－－－－－－－－－－－－－－－－－－－mysql connection failed timeout－－－－－－－－－－－－－－－
     5 =INFO REPORT==== 2010-11-05 16:23:21 ===
     6 I(<0.247.0>:ejabberd_odbc:212) : mysql connection failed:
     7 ** Reason: "timed out"
     8 ** Retry after: 30 seconds
     9 
    10 =ERROR REPORT==== 2010-11-05 16:23:21 ===
    11 E(<0.246.0>:ejabberd_odbc:528) : mysql_conn: Failed connecting to "192.168.0.223":3306 : {error,
    12                                                                                           "timeout"}
    13 
    14 =INFO REPORT==== 2010-11-05 16:23:21 ===
    15 I(<0.244.0>:ejabberd_odbc:212) : mysql connection failed:
    16 ** Reason: "timed out"
    17 ** Retry after: 30 seconds
    18 
    19 =ERROR REPORT==== 2010-11-05 16:23:21 ===
    20 W(<0.244.0>:ejabberd_odbc:281) : unexpected info in connecting: {mysql_conn,
    21                                                                  <0.246.0>,
    22                                                                  {error,
    23                                                                   connect_failed}}
    24 
    25 =ERROR REPORT==== 2010-11-05 16:23:21 ===
    26 E(<0.243.0>:ejabberd_odbc:528) : mysql_conn: Failed connecting to "192.168.0.223":3306 : {error,
    27                                                                                           "timeout"}
    28 
    29 =INFO REPORT==== 2010-11-05 16:23:21 ===
    30 I(<0.241.0>:ejabberd_odbc:212) : mysql connection failed:
    31 ** Reason: "timed out"
    32 ** Retry after: 30 seconds
    33 
    34 =ERROR REPORT==== 2010-11-05 16:23:21 ===
    35 W(<0.241.0>:ejabberd_odbc:281) : unexpected info in connecting: {mysql_conn,
    36                                                                  <0.243.0>,
    37                                                                  {error,