emqx开源版日志报错

[xiaoxuedong]

环境

• EMQX 版本：5.3.2
• 操作系统版本：CentOS7.9

错误日志

2024-03-01T09:28:59.509668+08:00 [error] msg: gen_rpc_client_auth_timeout, mfa: gen_rpc_auth:authenticate_client/3(109), error: timeout, peer: {{47,103,99,182},44206}
2024-03-01T09:28:59.513678+08:00 [error] State machine {acceptor,{{47,103,99,182},44206}} terminating. Reason: {badtcp,timeout}. Stack: [{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]. Last event: {{call,{<0.2211.0>,#Ref<0.959721128.2608332801.188162>}},{socket_ready,#Port<0.5268596>}}. State: {waiting_for_socket,{state,#Port<0.5268596>,tcp,gen_rpc_driver_tcp,tcp_closed,tcp_error,{{47,103,99,182},44206},disabled,disabled}}. Client gen_rpc_server_tcp stacktrace: [{prim_inet,accept0,3,},{inet_tcp,accept,2,[{file,“inet_tcp.erl”},{line,227}]},{gen_rpc_server,waiting_for_connection,3,[{file,“gen_rpc_server.erl”},{line,70}]},{gen_statem,loop_state_callback,11,[{file,“gen_statem.erl”},{line,1426}]}].
2024-03-01T09:28:59.513979+08:00 [error] crasher: initial call: gen_rpc_acceptor:init/1, pid: <0.32736.687>, registered_name: , exit: {{badtcp,timeout},[{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]}, ancestors: [gen_rpc_acceptor_sup,gen_rpc_sup,<0.2208.0>], message_queue_len: 0, messages: , links: [<0.2212.0>], dictionary: , trap_exit: true, status: running, heap_size: 6772, stack_size: 28, reductions: 12022; neighbours:
2024-03-01T09:28:59.514226+08:00 [error] Supervisor: {local,gen_rpc_acceptor_sup}. Context: child_terminated. Reason: {badtcp,timeout}. Offender: id=gen_rpc_acceptor,pid=<0.32736.687>.
2024-03-01T09:29:04.518661+08:00 [error] msg: gen_rpc_client_auth_timeout, mfa: gen_rpc_auth:authenticate_client/3(109), error: timeout, peer: {{47,103,99,182},44684}
2024-03-01T09:29:04.523198+08:00 [error] State machine {acceptor,{{47,103,99,182},44684}} terminating. Reason: {badtcp,timeout}. Stack: [{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]. Last event: {{call,{<0.2211.0>,#Ref<0.959721128.2608332801.188674>}},{socket_ready,#Port<0.5268605>}}. State: {waiting_for_socket,{state,#Port<0.5268605>,tcp,gen_rpc_driver_tcp,tcp_closed,tcp_error,{{47,103,99,182},44684},disabled,disabled}}. Client gen_rpc_server_tcp stacktrace: [{prim_inet,accept0,3,},{inet_tcp,accept,2,[{file,“inet_tcp.erl”},{line,227}]},{gen_rpc_server,waiting_for_connection,3,[{file,“gen_rpc_server.erl”},{line,70}]},{gen_statem,loop_state_callback,11,[{file,“gen_statem.erl”},{line,1426}]}].
2024-03-01T09:29:04.523507+08:00 [error] crasher: initial call: gen_rpc_acceptor:init/1, pid: <0.24.688>, registered_name: , exit: {{badtcp,timeout},[{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]}, ancestors: [gen_rpc_acceptor_sup,gen_rpc_sup,<0.2208.0>], message_queue_len: 0, messages: , links: [<0.2212.0>], dictionary: , trap_exit: true, status: running, heap_size: 6772, stack_size: 28, reductions: 12022; neighbours:
2024-03-01T09:29:04.523775+08:00 [error] Supervisor: {local,gen_rpc_acceptor_sup}. Context: child_terminated. Reason: {badtcp,timeout}. Offender: id=gen_rpc_acceptor,pid=<0.24.688>.
2024-03-01T09:29:09.528663+08:00 [error] msg: gen_rpc_client_auth_timeout, mfa: gen_rpc_auth:authenticate_client/3(109), error: timeout, peer: {{47,103,99,182},45548}
2024-03-01T09:29:09.533007+08:00 [error] State machine {acceptor,{{47,103,99,182},45548}} terminating. Reason: {badtcp,timeout}. Stack: [{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]. Last event: {{call,{<0.2211.0>,#Ref<0.959721128.2608332801.189132>}},{socket_ready,#Port<0.5268612>}}. State: {waiting_for_socket,{state,#Port<0.5268612>,tcp,gen_rpc_driver_tcp,tcp_closed,tcp_error,{{47,103,99,182},45548},disabled,disabled}}. Client gen_rpc_server_tcp stacktrace: [{prim_inet,accept0,3,},{inet_tcp,accept,2,[{file,“inet_tcp.erl”},{line,227}]},{gen_rpc_server,waiting_for_connection,3,[{file,“gen_rpc_server.erl”},{line,70}]},{gen_statem,loop_state_callback,11,[{file,“gen_statem.erl”},{line,1426}]}].
2024-03-01T09:29:09.533294+08:00 [error] crasher: initial call: gen_rpc_acceptor:init/1, pid: <0.62.688>, registered_name: , exit: {{badtcp,timeout},[{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]}, ancestors: [gen_rpc_acceptor_sup,gen_rpc_sup,<0.2208.0>], message_queue_len: 0, messages: , links: [<0.2212.0>], dictionary: , trap_exit: true, status: running, heap_size: 6772, stack_size: 28, reductions: 12022; neighbours:
2024-03-01T09:29:09.533555+08:00 [error] Supervisor: {local,gen_rpc_acceptor_sup}. Context: child_terminated. Reason: {badtcp,timeout}. Offender: id=gen_rpc_acceptor,pid=<0.62.688>.
2024-03-01T09:29:14.537662+08:00 [error] msg: gen_rpc_client_auth_timeout, mfa: gen_rpc_auth:authenticate_client/3(109), error: timeout, peer: {{47,103,99,182},46392}
2024-03-01T09:29:14.541954+08:00 [error] State machine {acceptor,{{47,103,99,182},46392}} terminating. Reason: {badtcp,timeout}. Stack: [{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]. Last event: {{call,{<0.2211.0>,#Ref<0.959721128.2608332801.189464>}},{socket_ready,#Port<0.5268621>}}. State: {waiting_for_socket,{state,#Port<0.5268621>,tcp,gen_rpc_driver_tcp,tcp_closed,tcp_error,{{47,103,99,182},46392},disabled,disabled}}. Client gen_rpc_server_tcp stacktrace: [{prim_inet,accept0,3,},{inet_tcp,accept,2,[{file,“inet_tcp.erl”},{line,227}]},{gen_rpc_server,waiting_for_connection,3,[{file,“gen_rpc_server.erl”},{line,70}]},{gen_statem,loop_state_callback,11,[{file,“gen_statem.erl”},{line,1426}]}].
2024-03-01T09:29:14.542235+08:00 [error] crasher: initial call: gen_rpc_acceptor:init/1, pid: <0.88.688>, registered_name: , exit: {{badtcp,timeout},[{gen_statem,loop_state_callback_result,11,[{file,“gen_statem.erl”},{line,1555}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,240}]}]}, ancestors: [gen_rpc_acceptor_sup,gen_rpc_sup,<0.2208.0>], message_queue_len: 0, messages: , links: [<0.2212.0>], dictionary: , trap_exit: true, status: running, heap_size: 6772, stack_size: 28, reductions: 12023; neighbours:
2024-03-01T09:29:14.542473+08:00 [error] Supervisor: {local,gen_rpc_acceptor_sup}. Context: child_terminated. Reason: {badtcp,timeout}. Offender: id=gen_rpc_acceptor,pid=<0.88.688>.

系统调优都做过也验证过，但是我发现我新的连接上没一会就断开了，反而是旧的连接我怎么删除都删不掉，过一会又会以未连接的状态出现

[blankalupo]

你是在单节点下，还是集群下产生了这个问题

[xiaoxuedong]

单节点下，设备数量我就模拟创建了1000多个主题，一个客户端连接下的

[xiaoxuedong]

还有一个现象很奇怪，连接一段时间后，我发布信息可以，但是接收信息没有了，EMQX上面是可以看到消息流入流出条数的

[xiaoxuedong]

然后过了大概几分钟，连接的客户端就从EMQX消失了，日志是这样的：
2024-03-01T15:49:20.284417+08:00 [warning] msg: unexpected_api_access, mfa: emqx_dashboard_not_found:init/2(25), request: #{bindings => #{},body_length => 0,cert => undefined,has_body => false,headers => #{<<“accept-encoding”>> => <<“gzip, x-gzip, deflate”>>,<<“host”>> => <<“47.101.131.14static”>>,<<“user-agent”>> => <<“Apache-HttpClient/5.1.3 (Java/1.8.0_342)”>>},host => <<“47.101.131.14static”>>,host_info => undefined,method => <<“GET”>>,path => <<“/emq.ico”>>,path_info => undefined,peer => {{113,215,189,16},31958},pid => <0.23130.692>,port => 80,qs => <<>>,ref => ‘http:dashboard’,scheme => <<“http”>>,sock => {{172,22,48,213},18083},streamid => 1,version => ‘HTTP/1.1’}
2024-03-01T16:45:20.641841+08:00 [warning] msg: unexpected_api_access, mfa: emqx_dashboard_not_found:init/2(25), request: #{bindings => #{},body_length => 0,cert => undefined,has_body => false,headers => #{<<“accept-encoding”>> => <<“gzip, x-gzip, deflate”>>,<<“host”>> => <<“47.101.131.14static”>>,<<“user-agent”>> => <<“Apache-HttpClient/5.1.3 (Java/1.8.0_342)”>>},host => <<“47.101.131.14static”>>,host_info => undefined,method => <<“GET”>>,path => <<“/emq.ico”>>,path_info => undefined,peer => {{113,215,189,247},28582},pid => <0.13241.693>,port => 80,qs => <<>>,ref => ‘http:dashboard’,scheme => <<“http”>>,sock => {{172,22,48,213},18083},streamid => 1,version => ‘HTTP/1.1’}
2024-03-01T17:17:45.254813+08:00 [warning] msg: authorization_permission_denied, mfa: emqx_authz:authorize_non_superuser/5(489), peername: 162.142.125.13:37526, clientid: CENSYS, topic: #, ipaddr: {162,142,125,13}, source: file, username: undefined
2024-03-01T17:18:38.110007+08:00 [warning] msg: socket_error, mfa: emqx_connection:handle_info/2(932), peername: 220.178.171.67:36412, clientid: server-java_client_prod1709271443297, reason: etimedout

[blankalupo]

你的系统上是不是设置了防火墙或则路由规则之类的东西，从日志上来看，网络是否有些问题

[xiaoxuedong]

@xiaoxuedong

etimedout

您好，您是说我部署EMQX环境也就是这个CentOS上面是不是有防火墙或者路由吗？这是阿里云服务器，没有设置什么路由，防护墙也是关着的，包括我本地服务的服务器防火墙也是关着的，这个日志里面的错误是和网络有关吗？

[xiaoxuedong]

我设置的keepalive是43200，但是他连一会就会出现msg: socket_error, mfa: emqx_connection:handle_info/2(932), peername: 220.178.171.67:39718, clientid: server-java_prod, reason: etimedout