How to best log (D)TLS information

[mrdeep1]

CoAP logging levels are determined by 2 functions - coap_set_log_level() and coap_dtls_set_log_level().

The examples of coap-client and coap-server set the log level to the same value in both functions.

The different TLS libraries are not consistent with how they handle coap_dtls_set_log_level() - some use COAP_LOG_CIPHERS(9) as a zero base for the different (internal to TLS) logging levels, others can log at higher (numerically less) levels than COAP_LOG_CIPHERS etc. Overall, the mechanisms here need to be consistent.

Furthermore, the TLS libraries have different upper limits for the more verbose logging (i.e different ranges for logging levels).

Should the logging level passed to coap_dtls_set_log_level() be the internal to TLS logging levels - i.e. start at 0 matching what the TLS library does when set to a logging level of 0 et.c. or should it be COAP_LOG_CIPHERS + TLS logging level?

• starting at 0 will cause additional logging for old executables or unchanged application source using a later version of libcoap.
• examples will need a different option to be able to define the TLS logging levels.

Should coap_dtls_set_log_level() become a dummy function that is no longer used with everything keyed of the value of level passed into coap_set_log_level()?

Should we be now calling COAP_LOG_CIPHERS COAP_LOG_TLS_BASE or COAP_LOG_TLS_L0 for better code readability (but retain COAP_LOG_CIPHERS for backwards source code compatibility)?

In terms of coap_log(), should the level parameter be COAP_LOG_TLS_L0 + TLS_level, so that it is possible to determine from the logs what level a particular TLS log entry is for (e.g. TLS1 or TLS7)?

• Using ALRT, WARN, INFO etc. (with no bias added) do not map easily into the TLS library logging levels.
• Users may still need to map TLS1 back to what logging level 1 means for that particular TLS library.

Other thoughts?

[obgm]

Thanks for bringing this up. Your assessment seems to indicate that we need a library-specific mapping of generic enums to library-specific values. As these can be defined at compile time, I see no big harm in this (other than the effort of finding a good mapping for each library). For the example programs, it might be worth splitting the CoAP log level from the DTLS log level.

[mrdeep1]

• With GnuTLS, the range is from 0 to 99, but realistically 10 gives you everything.
• With OpenSSL, libcoap sets the logging levels within the defined SSL_CTX_set_info_callback() callback. There is also available the SSL_CTX_set_msg_callback() function which is currently not used.
• With TinyDTLS the logging levels follow that of syslog, but are set in their own enum log_t. It does not currently support a callback to use coap_log(), and potentially coap_log()'s defined log handler. Easily fixed.
• With MbedTLS the range is from 0 to 4 using terms similar to syslog.

In terms of the coap_log() output, we can do some sort of mapping of the (D)TLS library levels back into EMRG, ALRT, DEBG etc. so that we output these entry descriptions for (D)TLS logging. The GnuTLS mapping will be the most difficult. However, I think we would need to create a coap_dtls_log() (so DTLS logging levels can be checked against instead of CoAP levels levels) if we go down the EMRG, ALRT etc. route to be used by the (D)TLS specific interface files.

Hence why I came up with the alternative of TLS0, TLS1 etc. logging levels where TLS0 maps (D)TLS library value 0 (which may be nothing logged or something depending on the library), TLS1 maps (D)TLS library value 1 etc. All we then need to do it try to document what TLS0, TLS1 etc. mean according to the appropriate (D)TLS library. We could say that the examples -v13 will generate logging output up to and including TLS3 if that helps (base bias is 10, not 9).

[With OSCORE, OSCORE specific information is logged at level 8, one above LOG_DEBUG in #764. Is this a CoAP logging level, or a (D)TLS library logging level - I think I would prefer it to be CoAP logging.]

If the examples have a new option, say, V, for (D)TLS logging, this will cause any existing binaries (including user applications) using the new library (or unchanged source) to log (D)TLS information with the logging level passed into coap_dtls_set_log_level() (the default is LOG_WARNING). Updating the source and recompiling would fix this, so not a major issue but could cause some short term confusion issues.. Is this acceptable?

[obgm]

I think there is no exclusive right or wrong here. We should go for a solution that most likely works well for most use cases. With TLSn (with a numeric n), one would always have to read the documentation what the particular log level includes. Why not TLS_EMERG, TLS_CRIT, etc. as with the other log level constants?

[mrdeep1]

Finding the documentation for the logging information in the different (D)TLS libraries was not straightforward, with bland statements along the lines of "the bigger the number, more detailed the logging" for MbedTLS.

The issue I have with TLS_EMERG is the length of the log line increases. As mentioned some time ago, my eyes like the the logging prefixes to be the same length so that the text is easy to scan down looking for anomalies. The level field is currently 4 chars. A way forward could be to have C_DEBG and D_DEBG (CoAP and DTLS respectively). So, for example it would look like

Jul 20 08:59:42.314 C_DEBG *  127.0.0.1:33244 <-> 127.0.0.1:5684 DTLS: sent 15 bytes
Jul 20 08:59:42.314 D_DEBG removed peer: 127.0.0.1:5684
Jul 20 08:59:42.314 C_DEBG ***removed session 0x7717c0

or it could be (adding in DTLS: for DTLS logging entries)

Jul 20 08:59:42.314 DEBG *  127.0.0.1:33244 <-> 127.0.0.1:5684 DTLS: sent 15 bytes
Jul 20 08:59:42.314 DEBG DTLS: removed peer: 127.0.0.1:5684
Jul 20 08:59:42.314 DEBG ***removed session 0x7717c0

[mrdeep1]

I have gone with

Jul 20 08:59:42.314 DEBG *  127.0.0.1:33244 <-> 127.0.0.1:5684 DTLS: sent 15 bytes
Jul 20 08:59:42.314 DTLS-DEBG removed peer: 127.0.0.1:5684
Jul 20 08:59:42.314 DEBG ***removed session 0x7717c0

with a DTLS- prefix for (D)TLS library logging. https://github.com/eclipse/tinydtls/pull/158 adds in the support for consistent logging within libcoap. Otherwise libcoap code is ready to become a PR when the tinydtls submodule is updated.