Ten thousand lines of logging when starting TLS connection

Questions / Help
,
1

Since upgrading to OTP-25, whenever a TLS connection is started, this causes an extreme amount of logging:

=PROGRESS REPORT==== 24-Jan-2023::10:29:24.145614 ===                                                                                                                                                                                                                                                                                                                                                                                       
    supervisor: {<0.849.0>,tls_dyn_connection_sup}                                                                                                                                                                                                                                                                                                                                                                                          
    started: [{pid,<0.852.0>},                                                                             
              {id,receiver},                                                                               
              {mfargs,                                                                                     
                  {ssl_gen_statem,start_link,                                                              
                      [client,<0.851.0>,"host.name.com",443,                                        
                       #Port<0.69>,                                                                        
                       {#{alpn_preferred_protocols => undefined,                                           
                          sni_hosts => [],early_data => undefined,                                         
                          hibernate_after => infinity,                                                     
                          ciphers =>                                                                       
                              [<<19,2>>,                          
                          ..... more than 10.000 lines removed ...
                           {socket_options,binary,raw,0,0,false},                                             
                        undefined},                                                                        
                       <0.789.0>,                                                                          
                       {gen_tcp,tcp,tcp_closed,tcp_error,tcp_passive}]}},                                  
              {restart_type,temporary},                                                                    
              {significant,true},                                                                          
              {shutdown,5000},                                                                             
              {child_type,worker}]

The majority of the 10000 (!) lines of logging is caused by a dump of the cacerts. This makes debugging very difficult, since it completely overflows the terminal.

Has anyone else seen this, and is there a solution?

2 Likes
2

I guess the easiest way to get rid of them is to not use SASL logs. Perhaps we can mitigate this in the future. Personally, I think all progress reports in SASL ought to be debug-level logging but this is legacy that is hard to change.

1 Like
3

We have this problem as well. As soon as we use some TLS configuration, all cacerts are logged in the SASL logs on info level.

To temporarily fix this, one can disable the progress logs with the following sys.config:

[
    {kernel, [
        {logger, [
            {handler, default, logger_std_h, #{
                filter_default => log,
                filters => [
                    {disable_progress, {fun logger_filters:progress/2, stop}}
                ]
            }}
        ]}
    ]},
].

(Note that this is just a minimal configuration, the default configuration for the default handler is actually a bit different:

1> logger:get_handler_config(default).
{ok,#{config => ...,
      filter_default => stop,
      filters =>
          [{remote_gl,{fun logger_filters:remote_gl/2,stop}},
           {domain,{fun logger_filters:domain/2,
                    {log,super,[otp,sasl]}}},
           {no_domain,{fun logger_filters:domain/2,
                       {log,undefined,[]}}}],
      formatter =>
          {logger_formatter,#{legacy_header => true,single_line => false}},
      id => default,level => all,module => logger_std_h}}
1 Like