rabbitmq / osiris

Log based streaming subsystem for RabbitMQ
Other
45 stars 10 forks source link

When peer connection that uses TLS closes, a stack trace s logged #149

Open luos opened 1 year ago

luos commented 1 year ago

Describe the bug

Hi,

When the replica gets disconnected there is a big crash in the logs. I don't think it causes any issues itself, it just prints a lot of a logs. It is present in 3.12.2 RabbitMQ, I tried to look at the osiris code and I don't think it has changed since.

The reason seems to be that the unwrapping of the sslsocket record should be done by https://github.com/erlang/otp/blob/c04923a7f00d01ab65923b70b73a14751f759f8a/lib/ssl/src/ssl.erl#L822.

I don't think it's fixed by https://github.com/rabbitmq/osiris/pull/127.

[error] <0.28805.6043>   crasher:
[error] <0.28805.6043>     initial call: osiris_replica:init/1
[error] <0.28805.6043>     pid: <0.28805.6043>
[error] <0.28805.6043>     registered_name: []
[error] <0.28805.6043>     exception error: no function clause matching
[error] <0.28805.6043>                      inet:tcp_close({sslsocket,
[error] <0.28805.6043>                                      {gen_tcp,#Port<0.375235>,tls_connection,
[error] <0.28805.6043>                                       [{option_tracker,<0.28821.6043>},
[error] <0.28805.6043>                                        {session_tickets_tracker,disabled},
[error] <0.28805.6043>                                        {session_id_tracker,<0.28769.6043>}]},
[error] <0.28805.6043>                                      [<0.28838.6043>,<0.28829.6043>]}) (inet.erl, line 2179)
[error] <0.28805.6043>       in function  osiris_replica:terminate/2 (src/osiris_replica.erl, line 583)
[error] <0.28805.6043>       in call from gen_server:try_terminate/3 (gen_server.erl, line 1161)
[error] <0.28805.6043>       in call from gen_server:terminate/10 (gen_server.erl, line 1351)
[error] <0.28805.6043>     ancestors: [osiris_server_sup,osiris_sup,<0.236.0>]
[error] <0.28805.6043>     message_queue_len: 1
[error] <0.28805.6043>     messages: [{'EXIT',<26355.25707.3991>,noconnection}]
[error] <0.28805.6043>     links: [<0.240.0>]
[error] <0.28805.6043>     dictionary: [{rand_seed,{#{bits => 58,jump => #Fun<rand.3.34006561>,
[error] <0.28805.6043>                                 next => #Fun<rand.0.34006561>,type => exsss,
[error] <0.28805.6043>                                 uniform => #Fun<rand.1.34006561>,
[error] <0.28805.6043>                                 uniform_n => #Fun<rand.2.34006561>},
[error] <0.28805.6043>                               [226521070241013009|90178930201845774]}}]
[error] <0.28805.6043>     trap_exit: true
[error] <0.28805.6043>     status: running
[error] <0.28805.6043>     heap_size: 10958
[error] <0.28805.6043>     stack_size: 28
[error] <0.28805.6043>     reductions: 1230731
[error] <0.28805.6043>   neighbours:
[error] <0.28805.6043> 
[error] <0.28796.6043>   crasher:
[error] <0.28796.6043>     initial call: osiris_replica:init/1
[error] <0.28796.6043>     pid: <0.28796.6043>
[error] <0.28796.6043>     registered_name: []
[error] <0.28796.6043>     exception error: no function clause matching
[error] <0.28796.6043>                      inet:tcp_close({sslsocket,
[error] <0.28796.6043>                                      {gen_tcp,#Port<0.375233>,tls_connection,
[error] <0.28796.6043>                                       [{option_tracker,<0.28736.6043>},
[error] <0.28796.6043>                                        {session_tickets_tracker,disabled},
[error] <0.28796.6043>                                        {session_id_tracker,<0.28806.6043>}]},
[error] <0.28796.6043>                                      [<0.28818.6043>,<0.28725.6043>]}) (inet.erl, line 2179)
[error] <0.28796.6043>       in function  osiris_replica:terminate/2 (src/osiris_replica.erl, line 583)
[error] <0.28796.6043>       in call from gen_server:try_terminate/3 (gen_server.erl, line 1161)
[error] <0.28796.6043>       in call from gen_server:terminate/10 (gen_server.erl, line 1351)
[error] <0.28796.6043>     ancestors: [osiris_server_sup,osiris_sup,<0.236.0>]
[error] <0.28796.6043>     message_queue_len: 1
[error] <0.28796.6043>     messages: [{'EXIT',<26355.10556.3991>,noconnection}]
[error] <0.28796.6043>     links: [<0.240.0>]
[error] <0.28796.6043>     dictionary: [{rand_seed,{#{bits => 58,jump => #Fun<rand.3.34006561>,
[error] <0.28796.6043>                                 next => #Fun<rand.0.34006561>,type => exsss,
[error] <0.28796.6043>                                 uniform => #Fun<rand.1.34006561>,
[error] <0.28796.6043>                                 uniform_n => #Fun<rand.2.34006561>},
[error] <0.28796.6043>                               [233705589416098505|223844803913714530]}}]
[error] <0.28796.6043>     trap_exit: true
[error] <0.28796.6043>     status: running
[error] <0.28796.6043>     heap_size: 6772
[error] <0.28796.6043>     stack_size: 28
[error] <0.28796.6043>     reductions: 1243496
[error] <0.28796.6043>   neighbours:
[error] <0.28796.6043> 
[error] <0.240.0>     supervisor: {local,osiris_server_sup}
[error] <0.240.0>     errorContext: child_terminated
[error] <0.240.0>     reason: {function_clause,
[error] <0.240.0>                 [{inet,tcp_close,
[error] <0.240.0>                      [{sslsocket,
[error] <0.240.0>                           {gen_tcp,#Port<0.375235>,tls_connection,
[error] <0.240.0>                               [{option_tracker,<0.28821.6043>},
[error] <0.240.0>                                {session_tickets_tracker,disabled},
[error] <0.240.0>                                {session_id_tracker,<0.28769.6043>}]},
[error] <0.240.0>                           [<0.28838.6043>,<0.28829.6043>]}],
[error] <0.240.0>                      [{file,"inet.erl"},{line,2179}]},
[error] <0.240.0>                  {osiris_replica,terminate,2,
[error] <0.240.0>                      [{file,"src/osiris_replica.erl"},{line,583}]},
[error] <0.240.0>                  {gen_server,try_terminate,3,
[error] <0.240.0>                      [{file,"gen_server.erl"},{line,1161}]},
[error] <0.240.0>                  {gen_server,terminate,10,
[error] <0.240.0>                      [{file,"gen_server.erl"},{line,1351}]},
[error] <0.240.0>                  {proc_lib,init_p_do_apply,3,
[error] <0.240.0>                      [{file,"proc_lib.erl"},{line,240}]}]}
[error] <0.240.0>     offender: [{pid,<0.28805.6043>},
[error] <0.240.0>                {id,"STREAM_NAME"},
[error] <0.240.0>                {mfargs,{osiris_replica,start_link,undefined}},
[error] <0.240.0>                {restart_type,temporary},
[error] <0.240.0>                {significant,false},
[error] <0.240.0>                {shutdown,5000},
[error] <0.240.0>                {child_type,worker}]
[error] <0.240.0> 
[error] <0.240.0>     supervisor: {local,osiris_server_sup}
[error] <0.240.0>     errorContext: child_terminated
[error] <0.240.0>     reason: {function_clause,
[error] <0.240.0>                 [{inet,tcp_close,
[error] <0.240.0>                      [{sslsocket,
[error] <0.240.0>                           {gen_tcp,#Port<0.375233>,tls_connection,
[error] <0.240.0>                               [{option_tracker,<0.28736.6043>},
[error] <0.240.0>                                {session_tickets_tracker,disabled},
[error] <0.240.0>                                {session_id_tracker,<0.28806.6043>}]},
[error] <0.240.0>                           [<0.28818.6043>,<0.28725.6043>]}],
[error] <0.240.0>                      [{file,"inet.erl"},{line,2179}]},
[error] <0.240.0>                  {osiris_replica,terminate,2,
[error] <0.240.0>                      [{file,"src/osiris_replica.erl"},{line,583}]},
[error] <0.240.0>                  {gen_server,try_terminate,3,
[error] <0.240.0>                      [{file,"gen_server.erl"},{line,1161}]},
[error] <0.240.0>                  {gen_server,terminate,10,
[error] <0.240.0>                      [{file,"gen_server.erl"},{line,1351}]},
[error] <0.240.0>                  {proc_lib,init_p_do_apply,3,
[error] <0.240.0>                      [{file,"proc_lib.erl"},{line,240}]}]}
[error] <0.240.0>     offender: [{pid,<0.28796.6043>},
[error] <0.240.0>                {id,"STREAM_NAME"},
[error] <0.240.0>                {mfargs,{osiris_replica,start_link,undefined}},
[error] <0.240.0>                {restart_type,temporary},
[error] <0.240.0>                {significant,false},
[error] <0.240.0>                {shutdown,5000},
[error] <0.240.0>                {child_type,worker}]
[error] <0.240.0> 

Reproduction steps

I have not looked into reproducing this.

Expected behavior

Only printing a relevant log message instead of a crash.

Additional context

No response