Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

error messages received and MQTT broker keep running up and down, very #13038

Closed
Tyco1234Jun opened this issue May 14, 2024 · 4 comments
Closed
Labels

Comments

@Tyco1234Jun
Copy link

What happened?

Following error logs continues for as long as 12 hours since server rebooted. What would be the potential causes?

2024-05-14T09:57:15.384000+09:00 [warning] msg: alarm_is_activated, mfa: emqx_alarm:do_actions/3(418), message: <<"connection congested: #{buffer => 4096,clientid => <<"JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC">>,conn_state => connected,connected_at => 1715648235255,high_msgq_watermark => 8192,high_watermark => 1048576,memory => 4552888,message_queue_len => 2313,peername => <<"127.0.0.1:55130">>,pid => <<"<0.25119.55>">>,proto_name => <<"MQTT">>,proto_ver => 4,recbuf => 65536,recv_cnt => 3,recv_oct => 87"...>>, name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">>
2024-05-14T09:57:15.386000+09:00 [warning] msg: busy_port, mfa: emqx_sys_mon:handle_info/2(182), portinfo: [{port,#Port<0.606072>},{name,"tcp_inet"},{links,[<0.25119.55>]},{id,654276},{connected,<0.25119.55>},{input,0},{output,2833490},{os_pid,undefined}], procinfo: [{pid,<0.25119.55>},{memory,4544056},{total_heap_size,543523},{heap_size,196650},{stack_size,33},{min_heap_size,233},{proc_lib_initial_call,{emqx_connection,init,['Argument__1','Argument__2','Argument__3','Argument__4']}},{initial_call,{proc_lib,init_p,5}},{current_stacktrace,[{erlang,port_command,3,[{file,"erlang.erl"},{line,3800}]},{esockd_transport,async_send,3,[{file,"esockd_transport.erl"},{line,153}]},{emqx_connection,send,2,[{file,"emqx_connection.erl"},{line,907}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,493}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,499}]},{emqx_connection,handle_recv,3,[{file,"emqx_connection.erl"},{line,455}]},{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,250}]}]},{registered_name,[]},{status,suspended},{message_queue_len,2212},{group_leader,<0.2532.0>},{priority,normal},{trap_exit,false},{reductions,173778},{last_calls,false},{catchlevel,4},{trace,0},{suspending,[]},{sequential_trace_token,[]},{error_handler,error_handler}]
2024-05-14T09:57:15.389000+09:00 [warning] msg: alarm_is_deactivated, mfa: emqx_alarm:do_actions/3(424), name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">>
2024-05-14T09:57:15.390000+09:00 [error] supervisor: {esockd_connection_sup,<0.25119.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2215}, offender: [{pid,<0.25119.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:17.445000+09:00 [error] supervisor: {esockd_connection_sup,<0.26693.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 3517}, offender: [{pid,<0.26693.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:19.400000+09:00 [error] supervisor: {esockd_connection_sup,<0.28221.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1819}, offender: [{pid,<0.28221.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:22.354000+09:00 [error] supervisor: {esockd_connection_sup,<0.29704.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 8495}, offender: [{pid,<0.29704.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:24.045000+09:00 [error] supervisor: {esockd_connection_sup,<0.31729.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1693}, offender: [{pid,<0.31729.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:26.084000+09:00 [error] supervisor: {esockd_connection_sup,<0.499.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1713}, offender: [{pid,<0.499.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:28.238000+09:00 [error] supervisor: {esockd_connection_sup,<0.2070.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 3085}, offender: [{pid,<0.2070.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:31.424000+09:00 [error] supervisor: {esockd_connection_sup,<0.3812.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1243}, offender: [{pid,<0.3812.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:33.576000+09:00 [error] supervisor: {esockd_connection_sup,<0.6153.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5484}, offender: [{pid,<0.6153.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:35.526000+09:00 [error] supervisor: {esockd_connection_sup,<0.7740.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2339}, offender: [{pid,<0.7740.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:37.611000+09:00 [warning] msg: alarm_is_activated, mfa: emqx_alarm:do_actions/3(418), message: <<"connection congested: #{buffer => 4096,clientid => <<"JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC">>,conn_state => connected,connected_at => 1715648257427,high_msgq_watermark => 8192,high_watermark => 1048576,memory => 11773968,message_queue_len => 6179,peername => <<"127.0.0.1:55170">>,pid => <<"<0.9370.56>">>,proto_name => <<"MQTT">>,proto_ver => 4,recbuf => 65536,recv_cnt => 3,recv_oct => 87"...>>, name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">>
2024-05-14T09:57:37.612000+09:00 [warning] msg: alarm_is_deactivated, mfa: emqx_alarm:do_actions/3(424), name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">>
2024-05-14T09:57:37.613000+09:00 [error] supervisor: {esockd_connection_sup,<0.9370.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 6347}, offender: [{pid,<0.9370.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:39.915000+09:00 [error] supervisor: {esockd_connection_sup,<0.10880.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1274}, offender: [{pid,<0.10880.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:42.412000+09:00 [error] supervisor: {esockd_connection_sup,<0.12509.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1671}, offender: [{pid,<0.12509.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:43.834000+09:00 [error] supervisor: {esockd_connection_sup,<0.14164.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5333}, offender: [{pid,<0.14164.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:45.825000+09:00 [error] supervisor: {esockd_connection_sup,<0.15633.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5447}, offender: [{pid,<0.15633.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:47.821000+09:00 [error] supervisor: {esockd_connection_sup,<0.17211.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5349}, offender: [{pid,<0.17211.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:50.386000+09:00 [error] supervisor: {esockd_connection_sup,<0.18739.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2405}, offender: [{pid,<0.18739.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:52.312000+09:00 [error] supervisor: {esockd_connection_sup,<0.20353.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 4539}, offender: [{pid,<0.20353.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:54.190000+09:00 [warning] msg: alarm_is_activated, mfa: emqx_alarm:do_actions/3(418), message: <<"connection congested: #{buffer => 4096,clientid => <<"JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC">>,conn_state => connected,connected_at => 1715648274068,high_msgq_watermark => 8192,high_watermark => 1048576,memory => 1373824,message_queue_len => 549,peername => <<"127.0.0.1:55201">>,pid => <<"<0.22051.56>">>,proto_name => <<"MQTT">>,proto_ver => 4,recbuf => 65536,recv_cnt => 3,recv_oct => 87,"...>>, name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">>
2024-05-14T09:57:54.193000+09:00 [warning] msg: busy_port, mfa: emqx_sys_mon:handle_info/2(182), portinfo: [{port,#Port<0.615944>},{name,"tcp_inet"},{links,[<0.22051.56>]},{id,733252},{connected,<0.22051.56>},{input,0},{output,3934864},{os_pid,undefined}], procinfo: [{pid,<0.22051.56>},{memory,2096920},{total_heap_size,246233},{heap_size,196650},{stack_size,33},{min_heap_size,233},{proc_lib_initial_call,{emqx_connection,init,['Argument__1','Argument__2','Argument__3','Argument__4']}},{initial_call,{proc_lib,init_p,5}},{current_stacktrace,[{erlang,port_command,3,[{file,"erlang.erl"},{line,3800}]},{esockd_transport,async_send,3,[{file,"esockd_transport.erl"},{line,153}]},{emqx_connection,send,2,[{file,"emqx_connection.erl"},{line,907}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,493}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,499}]},{emqx_connection,handle_recv,3,[{file,"emqx_connection.erl"},{line,455}]},{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,250}]}]},{registered_name,[]},{status,suspended},{message_queue_len,1491},{group_leader,<0.2532.0>},{priority,normal},{trap_exit,false},{reductions,208183},{last_calls,false},{catchlevel,4},{trace,0},{suspending,[]},{sequential_trace_token,[]},{error_handler,error_handler}]
2024-05-14T09:57:54.195000+09:00 [warning] msg: alarm_is_deactivated, mfa: emqx_alarm:do_actions/3(424), name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">>
2024-05-14T09:57:54.195000+09:00 [error] supervisor: {esockd_connection_sup,<0.22051.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1796}, offender: [{pid,<0.22051.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:56.309000+09:00 [error] supervisor: {esockd_connection_sup,<0.23562.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1142}, offender: [{pid,<0.23562.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:57:58.480000+09:00 [error] supervisor: {esockd_connection_sup,<0.25169.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2809}, offender: [{pid,<0.25169.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]
2024-05-14T09:58:00.940000+09:00 [error] supervisor: {esockd_connection_sup,<0.26789.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2957}, offender: [{pid,<0.26789.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter =>


What did you expect to happen?

No error messages in the log

How can we reproduce it (as minimally and precisely as possible)?

No response

Anything else we need to know?

No response

EMQX version

$ ./bin/emqx_ctl broker
# paste output here

OS version

# On Linux:
$ cat /etc/os-release
# paste output here
$ uname -a
# paste output here

Log files

2024-05-14T09:57:15.384000+09:00 [warning] msg: alarm_is_activated, mfa: emqx_alarm:do_actions/3(418), message: <<"connection congested: #{buffer => 4096,clientid => <<\"JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC\">>,conn_state => connected,connected_at => 1715648235255,high_msgq_watermark => 8192,high_watermark => 1048576,memory => 4552888,message_queue_len => 2313,peername => <<\"127.0.0.1:55130\">>,pid => <<\"<0.25119.55>\">>,proto_name => <<\"MQTT\">>,proto_ver => 4,recbuf => 65536,recv_cnt => 3,recv_oct => 87"...>>, name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">> 2024-05-14T09:57:15.386000+09:00 [warning] msg: busy_port, mfa: emqx_sys_mon:handle_info/2(182), portinfo: [{port,#Port<0.606072>},{name,"tcp_inet"},{links,[<0.25119.55>]},{id,654276},{connected,<0.25119.55>},{input,0},{output,2833490},{os_pid,undefined}], procinfo: [{pid,<0.25119.55>},{memory,4544056},{total_heap_size,543523},{heap_size,196650},{stack_size,33},{min_heap_size,233},{proc_lib_initial_call,{emqx_connection,init,['Argument__1','Argument__2','Argument__3','Argument__4']}},{initial_call,{proc_lib,init_p,5}},{current_stacktrace,[{erlang,port_command,3,[{file,"erlang.erl"},{line,3800}]},{esockd_transport,async_send,3,[{file,"esockd_transport.erl"},{line,153}]},{emqx_connection,send,2,[{file,"emqx_connection.erl"},{line,907}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,493}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,499}]},{emqx_connection,handle_recv,3,[{file,"emqx_connection.erl"},{line,455}]},{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,250}]}]},{registered_name,[]},{status,suspended},{message_queue_len,2212},{group_leader,<0.2532.0>},{priority,normal},{trap_exit,false},{reductions,173778},{last_calls,false},{catchlevel,4},{trace,0},{suspending,[]},{sequential_trace_token,[]},{error_handler,error_handler}] 2024-05-14T09:57:15.389000+09:00 [warning] msg: alarm_is_deactivated, mfa: emqx_alarm:do_actions/3(424), name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">> 2024-05-14T09:57:15.390000+09:00 [error] supervisor: {esockd_connection_sup,<0.25119.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2215}, offender: [{pid,<0.25119.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:17.445000+09:00 [error] supervisor: {esockd_connection_sup,<0.26693.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 3517}, offender: [{pid,<0.26693.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:19.400000+09:00 [error] supervisor: {esockd_connection_sup,<0.28221.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1819}, offender: [{pid,<0.28221.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:22.354000+09:00 [error] supervisor: {esockd_connection_sup,<0.29704.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 8495}, offender: [{pid,<0.29704.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:24.045000+09:00 [error] supervisor: {esockd_connection_sup,<0.31729.55>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1693}, offender: [{pid,<0.31729.55>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:26.084000+09:00 [error] supervisor: {esockd_connection_sup,<0.499.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1713}, offender: [{pid,<0.499.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:28.238000+09:00 [error] supervisor: {esockd_connection_sup,<0.2070.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 3085}, offender: [{pid,<0.2070.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:31.424000+09:00 [error] supervisor: {esockd_connection_sup,<0.3812.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1243}, offender: [{pid,<0.3812.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:33.576000+09:00 [error] supervisor: {esockd_connection_sup,<0.6153.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5484}, offender: [{pid,<0.6153.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:35.526000+09:00 [error] supervisor: {esockd_connection_sup,<0.7740.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2339}, offender: [{pid,<0.7740.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:37.611000+09:00 [warning] msg: alarm_is_activated, mfa: emqx_alarm:do_actions/3(418), message: <<"connection congested: #{buffer => 4096,clientid => <<\"JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC\">>,conn_state => connected,connected_at => 1715648257427,high_msgq_watermark => 8192,high_watermark => 1048576,memory => 11773968,message_queue_len => 6179,peername => <<\"127.0.0.1:55170\">>,pid => <<\"<0.9370.56>\">>,proto_name => <<\"MQTT\">>,proto_ver => 4,recbuf => 65536,recv_cnt => 3,recv_oct => 87"...>>, name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">> 2024-05-14T09:57:37.612000+09:00 [warning] msg: alarm_is_deactivated, mfa: emqx_alarm:do_actions/3(424), name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">> 2024-05-14T09:57:37.613000+09:00 [error] supervisor: {esockd_connection_sup,<0.9370.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 6347}, offender: [{pid,<0.9370.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:39.915000+09:00 [error] supervisor: {esockd_connection_sup,<0.10880.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1274}, offender: [{pid,<0.10880.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:42.412000+09:00 [error] supervisor: {esockd_connection_sup,<0.12509.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1671}, offender: [{pid,<0.12509.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:43.834000+09:00 [error] supervisor: {esockd_connection_sup,<0.14164.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5333}, offender: [{pid,<0.14164.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:45.825000+09:00 [error] supervisor: {esockd_connection_sup,<0.15633.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5447}, offender: [{pid,<0.15633.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:47.821000+09:00 [error] supervisor: {esockd_connection_sup,<0.17211.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 5349}, offender: [{pid,<0.17211.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:50.386000+09:00 [error] supervisor: {esockd_connection_sup,<0.18739.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2405}, offender: [{pid,<0.18739.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:52.312000+09:00 [error] supervisor: {esockd_connection_sup,<0.20353.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 4539}, offender: [{pid,<0.20353.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:54.190000+09:00 [warning] msg: alarm_is_activated, mfa: emqx_alarm:do_actions/3(418), message: <<"connection congested: #{buffer => 4096,clientid => <<\"JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC\">>,conn_state => connected,connected_at => 1715648274068,high_msgq_watermark => 8192,high_watermark => 1048576,memory => 1373824,message_queue_len => 549,peername => <<\"127.0.0.1:55201\">>,pid => <<\"<0.22051.56>\">>,proto_name => <<\"MQTT\">>,proto_ver => 4,recbuf => 65536,recv_cnt => 3,recv_oct => 87,"...>>, name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">> 2024-05-14T09:57:54.193000+09:00 [warning] msg: busy_port, mfa: emqx_sys_mon:handle_info/2(182), portinfo: [{port,#Port<0.615944>},{name,"tcp_inet"},{links,[<0.22051.56>]},{id,733252},{connected,<0.22051.56>},{input,0},{output,3934864},{os_pid,undefined}], procinfo: [{pid,<0.22051.56>},{memory,2096920},{total_heap_size,246233},{heap_size,196650},{stack_size,33},{min_heap_size,233},{proc_lib_initial_call,{emqx_connection,init,['Argument__1','Argument__2','Argument__3','Argument__4']}},{initial_call,{proc_lib,init_p,5}},{current_stacktrace,[{erlang,port_command,3,[{file,"erlang.erl"},{line,3800}]},{esockd_transport,async_send,3,[{file,"esockd_transport.erl"},{line,153}]},{emqx_connection,send,2,[{file,"emqx_connection.erl"},{line,907}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,493}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,499}]},{emqx_connection,handle_recv,3,[{file,"emqx_connection.erl"},{line,455}]},{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,250}]}]},{registered_name,[]},{status,suspended},{message_queue_len,1491},{group_leader,<0.2532.0>},{priority,normal},{trap_exit,false},{reductions,208183},{last_calls,false},{catchlevel,4},{trace,0},{suspending,[]},{sequential_trace_token,[]},{error_handler,error_handler}] 2024-05-14T09:57:54.195000+09:00 [warning] msg: alarm_is_deactivated, mfa: emqx_alarm:do_actions/3(424), name: <<"conn_congestion/JCIDM_AF12C9E8_E458_40A1_A1FE_E0E6CD1943CC/undefined">> 2024-05-14T09:57:54.195000+09:00 [error] supervisor: {esockd_connection_sup,<0.22051.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1796}, offender: [{pid,<0.22051.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:56.309000+09:00 [error] supervisor: {esockd_connection_sup,<0.23562.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 1142}, offender: [{pid,<0.23562.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:57:58.480000+09:00 [error] supervisor: {esockd_connection_sup,<0.25169.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2809}, offender: [{pid,<0.25169.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}] 2024-05-14T09:58:00.940000+09:00 [error] supervisor: {esockd_connection_sup,<0.26789.56>}, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2957}, offender: [{pid,<0.26789.56>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter =>
@zmstone
Copy link
Member

zmstone commented May 14, 2024

Hi @Tyco1234Jun
Please check syslog to see if the service is getting OOM killed by the OS.

@Tyco1234Jun
Copy link
Author

Tyco1234Jun commented May 14, 2024

Hi @Tyco1234Jun Please check syslog to see if the service is getting OOM killed by the OS.

Thanks, I will.
So potentially too much memory is in use in OS?

@zmstone
Copy link
Member

zmstone commented May 16, 2024

@Tyco1234Jun
In your logs, there are congestion and message_queue_too_long errors
it indicates that the subscribers are not consuming the messages fast enough, caused a lot of message to pile up in RAM.

@Tyco1234Jun
Copy link
Author

@zmstone Thank you so much! Understood it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants