使用exproto进行压力测试时报 msg: call_conn_process_crashed，并且发现部分连接关闭时，grpc server并没有收到onSocketClose的回调

2275433755 · 2023 年3 月 21 日 09:10

错误报告

环境

EMQX 版本：5.0.20
操作系统版本：windows 10

重现此问题的步骤

exproto的grpc server
启动emqx，在界面上配置好相关的监听器（监听19008），grpc server地址
启动Jmeter进行压力测试，线程数250，持续时间30s，添加了TCP采样器，建立连接并发送16进制报文 7878110108642570500001748039000200216BEC0D0A

预期行为

grpc server应该正常收到所有连接的建立连接和关闭连接的回调

实际行为

grpc server（Java实现的）只有收到了一部分的连接回调，关闭连接的回调应该是丢失了很多，可能是grpc server处理太慢，但是grpc server是根据github上的demo改的，只做了发送认证请求（web界面没配置接入认证），发布和订阅操作，理论上不应该很慢才对，grpc server和emqx都是本机。

功能请求

描述你需要的功能

为什么你需要这个功能

其他

2023-03-21T16:24:45.307000+08:00 [warning] msg: unexpected_call, mfa: emqx_exproto_channel:handle_call/3, line: 473, peername: 192.168.113.128:3060, call: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}
2023-03-21T16:24:45.306000+08:00 [warning] msg: unexpected_call, mfa: emqx_exproto_channel:handle_call/3, line: 473, peername: 192.168.113.128:3052, call: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}
2023-03-21T16:24:45.307000+08:00 [warning] msg: unexpected_call, mfa: emqx_exproto_channel:handle_call/3, line: 473, peername: 192.168.113.128:3044, call: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}
2023-03-21T16:24:45.741000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADPYAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3318.0>,{send,<<120,120,5,1,0,33,248,222,13,10>>},5000]}}}, request: {send,<<120,120,5,1,0,33,248,222,13,10>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,send,2,[{file,“emqx_exproto_gsvr.erl”},{line,53}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:45.749000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADNwAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3292.0>,{send,<<120,120,5,1,0,33,248,222,13,10>>},5000]}}}, request: {send,<<120,120,5,1,0,33,248,222,13,10>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,send,2,[{file,“emqx_exproto_gsvr.erl”},{line,53}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:45.760000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADOsAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3307.0>,{send,<<120,120,5,1,0,33,248,222,13,10>>},5000]}}}, request: {send,<<120,120,5,1,0,33,248,222,13,10>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,send,2,[{file,“emqx_exproto_gsvr.erl”},{line,53}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:45.772000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADPsAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3323.0>,{send,<<120,120,5,1,0,33,248,222,13,10>>},5000]}}}, request: {send,<<120,120,5,1,0,33,248,222,13,10>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,send,2,[{file,“emqx_exproto_gsvr.erl”},{line,53}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:45.774000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADPcAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3319.0>,{send,<<120,120,5,1,0,33,248,222,13,10>>},5000]}}}, request: {send,<<120,120,5,1,0,33,248,222,13,10>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,send,2,[{file,“emqx_exproto_gsvr.erl”},{line,53}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.073000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADUoAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3402.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.073000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADRcAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3351.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.073000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADeYAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3558.0>,{auth,#{clientid => <<“exproto-stuc383-641969cd6ad3462a50c0e109”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969cd6ad3462a50c0e109”>>},<<“exproto-stuc383-641969cd6ad3462a50c0e109”>>},5000]}}}, request: {auth,#{clientid => <<“exproto-stuc383-641969cd6ad3462a50c0e109”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969cd6ad3462a50c0e109”>>},<<“exproto-stuc383-641969cd6ad3462a50c0e109”>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,authenticate,2,[{file,“emqx_exproto_gsvr.erl”},{line,86}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.073000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADRoAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3354.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.076000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADdQAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3540.0>,{auth,#{clientid => <<“exproto-stuc383-641969cd6ad3462a50c0e107”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969cd6ad3462a50c0e107”>>},<<“exproto-stuc383-641969cd6ad3462a50c0e107”>>},5000]}}}, request: {auth,#{clientid => <<“exproto-stuc383-641969cd6ad3462a50c0e107”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969cd6ad3462a50c0e107”>>},<<“exproto-stuc383-641969cd6ad3462a50c0e107”>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,authenticate,2,[{file,“emqx_exproto_gsvr.erl”},{line,86}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.073000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADZQAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3476.0>,{auth,#{clientid => <<“exproto-stuc383-641969cd6ad3462a50c0e10a”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969cd6ad3462a50c0e10a”>>},<<“exproto-stuc383-641969cd6ad3462a50c0e10a”>>},5000]}}}, request: {auth,#{clientid => <<“exproto-stuc383-641969cd6ad3462a50c0e10a”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969cd6ad3462a50c0e10a”>>},<<“exproto-stuc383-641969cd6ad3462a50c0e10a”>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,authenticate,2,[{file,“emqx_exproto_gsvr.erl”},{line,86}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.166000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADVIAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3410.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.166000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADSUAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3365.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.167000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADT4AAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3390.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.182000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADQIAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3330.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.183000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADcEAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3521.0>,{auth,#{clientid => <<“exproto-stuc383-641969ce6ad3462a50c0e110”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969ce6ad3462a50c0e110”>>},<<“exproto-stuc383-641969ce6ad3462a50c0e110”>>},5000]}}}, request: {auth,#{clientid => <<“exproto-stuc383-641969ce6ad3462a50c0e110”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969ce6ad3462a50c0e110”>>},<<“exproto-stuc383-641969ce6ad3462a50c0e110”>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,authenticate,2,[{file,“emqx_exproto_gsvr.erl”},{line,86}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.184000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADREAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3345.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.182000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADToAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3386.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.184000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADXMAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3443.0>,{auth,#{clientid => <<“exproto-stuc383-641969ce6ad3462a50c0e111”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969ce6ad3462a50c0e111”>>},<<“exproto-stuc383-641969ce6ad3462a50c0e111”>>},5000]}}}, request: {auth,#{clientid => <<“exproto-stuc383-641969ce6ad3462a50c0e111”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969ce6ad3462a50c0e111”>>},<<“exproto-stuc383-641969ce6ad3462a50c0e111”>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,authenticate,2,[{file,“emqx_exproto_gsvr.erl”},{line,86}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.185000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADR0AAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3357.0>,{subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0},5000]}}}, request: {subscribe_from_client,<<“/sys/864257050000174/cmd/request/+”>>,0}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,subscribe,2,[{file,“emqx_exproto_gsvr.erl”},{line,143}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-03-21T16:24:46.186000+08:00 [error] msg: call_conn_process_crashed, mfa: emqx_exproto_gsvr:call/2, line: 188, conn_str: <<“g1hkAA5lbXF4QDEyNy4wLjAuMQAADeMAAAAAAAAAAw==”>>, reason: {exit,{noproc,{gen_server,call,[<0.3555.0>,{auth,#{clientid => <<“exproto-stuc383-641969ce6ad3462a50c0e113”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969ce6ad3462a50c0e113”>>},<<“exproto-stuc383-641969ce6ad3462a50c0e113”>>},5000]}}}, request: {auth,#{clientid => <<“exproto-stuc383-641969ce6ad3462a50c0e113”>>,mountpoint => <<>>,proto_name => <<“stuc383”>>,proto_ver => <<>>,username => <<“exproto-stuc383-641969ce6ad3462a50c0e113”>>},<<“exproto-stuc383-641969ce6ad3462a50c0e113”>>}, stacktrace: [{gen_server,call,3,[{file,“gen_server.erl”},{line,247}]},{emqx_exproto_gsvr,call,2,[{file,“emqx_exproto_gsvr.erl”},{line,173}]},{emqx_exproto_gsvr,authenticate,2,[{file,“emqx_exproto_gsvr.erl”},{line,86}]},{grpc_stream,handle_in,2,[{file,“grpc_stream.erl”},{line,256}]},{grpc_stream,events,2,[{file,“grpc_stream.erl”},{line,214}]},{grpc_stream,before_loop,1,[{file,“grpc_stream.erl”},{line,181}]},{grpc_stream,init,2,[{file,“grpc_stream.erl”},{line,119}]},{cowboy_handler,execute,2,[{file,“cowboy_handler.erl”},{line,41}]},{cowboy_stream_h,execute,3,[{file,“cowboy_stream_h.erl”},{line,318}]},{cowboy_stream_h,request_process,3,[{file,“cowboy_stream_h.erl”},{line,302}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]

heeejianbo · 2023 年3 月 22 日 02:47

你好，看起来像是 EMQX 侧的 gRPC 客户端崩溃掉了，方便把所有的日文件发来看看吗？
另外，

启动Jmeter进行压力测试，线程数250，持续时间30s，添加了TCP采样器

这里的意思是，每秒只建立了 250 个连接吗？

2275433755 · 2023 年3 月 22 日 06:37

Jmeter配置

今天我重新测试了，一开始我添加的TCP取样器不设置响应超时，250线程好像没太大问题，最多就是报msg: unexpected_call，设置了500线程，响应超时1000毫秒，就又出现昨天的情况了

我用arthas看了下处理时间，没压测的时候，就单独用客户端模拟器连接，发送了认证请求要5-10毫秒左右

Exproto.ClientInfo clientInfo = Exproto.ClientInfo.newBuilder()
                        .setClientid(clientId)
                        .setProtoName(name())
                        .setUsername(clientId)
                        .build();
                Exproto.AuthenticateRequest authenticateRequest = Exproto.AuthenticateRequest.newBuilder()
                        .setClientinfo(clientInfo)
                        .setConn(request.getConn())
                        .setPassword(clientId)
                        .build();
                Exproto.CodeResponse authenticateResponse = blockingStub.authenticate(authenticateRequest);

如下图

压测的时候发现发送请求的时间达到了200毫秒左右，
如下图

以下是采集的日志：
jemter-test-ip.zip (445.0 KB)
emqx.log.zip (500.4 KB)

2275433755 · 2023 年3 月 22 日 06:48

工程里的主要逻辑，onSocketCreate会发送authenticate请求，onReceiveBytes会解析报文，给设备订阅主题，同时将解析出来的报文实体以Json格式发送到某个主题

2275433755 · 2023 年3 月 22 日 09:50

应该是同时启动250线程，每个线程建立会一个连接，然后发送报文，等待响应，然后关闭连接，重复这个过程，持续30秒

heeejianbo · 2023 年3 月 23 日 01:12

msg: unexpected_call 这应该是一个设计问题，可能是由于向 Java 的 gRPC 服务使用单向流的方式发送请求导致的
TCP 取样器，响应超时1000毫秒 方便解释下这个参数的作用吗？
authenticate() 函数超时 200ms 这个肯定是有问题的，方便用 tcpdump 抓下 emqx ↔ java 双向 2 个 gRPC 端口的包吗?
压测的时候可以开启 emqx 的监控，看看是否有什么异常 bin/emqx eval 'observer_cli:start()'

2275433755 · 2023 年3 月 23 日 01:30

TCP 取样器，响应超时1000毫秒 方便解释下这个参数的作用吗？

这个参数主要是测试的流程的，就是我期望线程发起的TCP连接发送报文后，能够在 1000 毫秒内能够得到服务器的响应，如果超过 1000 毫秒，会把这一次的流程判定为失败。这算是一个比较重要的指标，当然这个时间是可以调整的，一般测试过程会统计失败率，主要是看客户能够容忍多大的响应时间和失败率。

我等会儿重新测试下，然后看下怎么抓包

2275433755 · 2023 年3 月 23 日 09:13

windows抓包有点困难，我把java grpc server放到了内网的Linux服务器上跑
以下是tcpdump日志
log.zip (2.5 MB)
下面这些是控制台？看不懂这块内容

2275433755 · 2023 年3 月 23 日 09:14

emq还是放在原来的windows系统上

heeejianbo · 2023 年3 月 23 日 10:27

要用 tcpdump -i any port <your-port-number> -vvn -w filename.cap 抓的，<your-port-number> 换成你的要抓的端口号，不然我这边得wireshark打不开的…

2275433755 · 2023 年3 月 23 日 11:59

我重新抓了log, 抓的端口是6911
log.zip (3.2 MB)

2275433755 · 2023 年3 月 24 日 00:41

感觉有可能是我代码中都使用 blockingStub 发送认证、发布、订阅的请求，同时所有设备共享了同一个channel 造成阻塞

2275433755 · 2023 年3 月 24 日 00:43

在 Java grpc server 中多个 blockingStub 共用一个 channel 发送认证、发布、订阅请求

2275433755 · 2023 年3 月 29 日 03:14

你好，有进展吗？我发现我代码里就算是改造成FututreStub，并且使用一个使用一个固定数量的Channel池进行复用，还是会出现 EMQX侧的gRPC客户端线程崩溃的现象，只不过是日志中出现的好像少了一些，但是 msg: unexpected_call 的日志好像变多了

heeejianbo · 2023 年3 月 29 日 06:28

抱歉，最近遗漏了你的消息。建议还是阻塞的方式好一些的，不然太多 unexpected_call 比较影响业务的。目前主要问题还是需要找到：

调用 Authenticate 接口，存在 200ms+ 的延迟
call_conn_process_crashed 错误的具体原因（猜测是过多请求阻塞了，导致处理该请求是你的客户端已经离线了，才打印的改日志）

方便来约一个线上的调试吗？这样更方便一些，方式可以发我邮箱（heeejianbo@gmail.com)

2275433755 · 2023 年3 月 29 日 08:15

已经发送给你了，看下是否方便