Forum Discussion

Ed_Summers's avatar
Ed_Summers
Icon for Nimbostratus rankNimbostratus
Oct 18, 2016

Attributing object to log messages

Since upgrading to v12.1.1 we're seeing SSL errors in /var/log/ltm. I believe this is due to behavior starting in v12.0 per SOL15292 ("Note: Beginning in 12.0.0, the BIG-IP system automatically logs SSL handshake failure information through standard logging"). However the log messages (samples below) do not indicate to which object they are attributed. Is there a way to determine which object throws these errors? Some (no shared ciphers) may not require further scrutiny but would like to trace some down to see if issue is something we need to pursue further.

Sample messages (timestamp and hostname removed; all following appear as 'warning' level):

 

tmm[22716]: 01260009:4: Connection error: ssl_cn_decrypt_fin_cb:2034: fin decryption failed (20)
tmm7[22717]: 01260009:4: Connection error: ssl_cn_decrypt_fin_cb:2034: fin decryption failed (20)
tmm5[22717]: 01260009:4: Connection error: hud_ssl_handler:1224: codec alert (20)
tmm3[22716]: 01260009:4: Connection error: ssl_passthru:4015: not SSL (40)
tmm4[22717]: 01260009:4: Connection error: ssl_passthru:4015: not SSL (40)
tmm4[22717]: 01260009:4: Connection error: ssl_hs_rxhello:7295: unsupported version (40)
tmm3[22716]: 01260009:4: Connection error: hud_ssl_handler:1224: codec alert (20)

 

My question may be better stated as: "Is there a document relating the log.ssl.level DB variable to the information logged to /var/log/ltm?" I see SOL17045 regarding some server-side logging that requires debugging and was hoping to find something documented rather than 'play' with log levels and observe results.

  • We saw this behavior upgrading from 11.6.1 to 12.1.1 HF1 and opened a ticket with f5. They have responded that we have an unusual level of ssl connection errors than they're used to seeing and I'm waiting to hear back from their findings. I'll update you once I know more.

     

  • Thanks Darren. If you are willing to share I'd be interested in the generic results of your support issue. I may also generate a ticket regarding my original question as well so we can track down the virtuals experiencing these errors. I may wait until after we upgrade to HF3 to resolve issues with bug 606573 ['FTP control channel connections (port 21) fail to establish through a SNAT object'].

     

    Right now I'm under the assumption that these errors have been present prior to the upgrade and are only now visible due to logging changes.

     

  • All - Sorry for the delay. We never pursued this further as it appears to be benign failures (clients trying to connect via prohibited protocols, etc) that were always present but only now logged due to logging changes in newer versions. I asked support about getting additional information but the tech was unable to provide more info other than 'enable logging at debug level' as noted in K17045. I work in a risk-adverse environment so the issue was dropped as it is not attributed to a production issue.

     

    The only other bit of information I found since this post was K5532, which outlines the logging levels available for certain event types. Not much help as it doesn't indicate what messages would be logged at each level so one cannot determine the level of logging that would need to be enabled. If I have time later I'll set up a test in my home lab to see if any level other than DEBUG provides any useful information. If I find something of interest I'll post here.

     

    As of now, best information I have is to assess your current resource load then enable debug logging for SSL traffic per K17045.

     

  • Ran out of time looking at this in the lab today. Maybe someone has additional details that would fill in the gaps on SSL log messages below. I didn't have time to dig further this morning.

    • Virtual Server: /Common/test_https
    • VIP: 10.1.0.65
    • SSL bridged; custom client-ssl profile with cipher string 'DEFAULT:!SSLv3' and default serverssl profile server-side

    Test 1: Connect to the virtual server using SSLv3 and view /var/log/ltm

    When log.ssl.level = Warning (default value)

    Sep 7 01:42:20 lb1 warning tmm1[24695]: 01260009:4: Connection error: ssl_hs_rxhello:7344: unsupported version (40)

    I then increased logging to Debug and tried again. For this test the only additional message came at the Info level:

     

    Sep  7 01:44:26 lb1 warning tmm3[24695]: 01260009:4: Connection error: ssl_hs_rxhello:7344: unsupported version (40)
    Sep  7 01:44:26 lb1 info tmm3[24695]: 01260013:6: SSL Handshake failed for TCP 172.16.1.132:59968 -> 10.1.0.65:443
    

     

    Second test was connecting to the virtual using HTTP instead of HTTPS. Even at the debug level only the following message was logged:

    Sep 7 01:46:35 lb1 warning tmm1[24695]: 01260009:4: Connection error: ssl_passthru:4021: not SSL (40)

    The partial answer to my original question: Debug isn't necessarily required to obtain attribution of the error to an object for certain errors. In this test we can attribute the virtual at Info logging level for unsupported protocol version errors, but no attribution was available for the 'not SSL' error.

    /var/run/bigip_error_maps.dat contains a mapping of error messages (including codes) to log files and levels (Reference: K6420). I thought I would be able to grep the file for all SSL error codes to get an idea at which level they would be logged. Searching the three codes above resulted in the following:

     

    0 LOG_WARNING   01260009 BIGIP_SSL_SSLERR_CONN "Connection error: %s:%d: %s (%d)" 
    0 LOG_WARNING   01260013 BIGIP_SSL_SSLERR_HANDSHAKE_FAILED "Not used -- implemented via new API to meet ICSA requirements; see ssl.c." 
    

     

    The second error (that provided virtual attribution) notes that it is 'Not used' (it also isn't currently logged at the Warn level). I searched the filesystem for ssl.c but turned up nothing. Not surprising - I wouldn't expect to find source code on the system.

    Grepped all files in /var/run for 'BIGIP_SSL_SSLERR_HANDSHAKE' but could not find a file with that error message. Apparently the SSL messages are handled elsewhere in current versions.

    It is possible that the Info log level for log.ssl.level may provide what is needed but I can't say for sure. Practically - if your system isn't heavily loaded enable Debug level temporarily to get your troubleshooting done. If you're uncertain about the resource load - consult F5 Support. I'm still interested in knowing if/where the SSL messages are now listed, if they're even in a text file now.

  • In production we are seeing these error message and as you mentioned earlier in 12.x logging level changes causing more verbose logging, We are not seeing any customer impact, I have reduce SSL logging level to from warning to Error which stopped errors in /var/log/ltm