TLS handshakes traceability

[krizhanovsky]

Also see #1454 as a parent issue

Motivation

At the moment I see many TLS errors in the logs for our web site:

root@Web:/var/log/vm-logs# tail site-01.log 
[1091003.544952] [tempesta tls] Warning: TLS: server requested by client is not known.
[1091003.549718] [tempesta fw] Warning: Unrecognized TLS receive return code -0x7900, drop packet
[1091075.634226] [tempesta tls] Warning: TLS: server requested by client is not known.
[1091075.638676] [tempesta fw] Warning: Unrecognized TLS receive return code -0x7900, drop packet
[1092296.243290] [tempesta tls] Warning: TLS: server requested by client is not known.
[1092296.247653] [tempesta fw] Warning: Unrecognized TLS receive return code -0x7900, drop packet
[1092346.066903] [tempesta tls] Warning: TLS: server requested by client is not known.
[1092346.071277] [tempesta fw] Warning: Unrecognized TLS receive return code -0x7900, drop packet
[1092442.606719] [tempesta tls] Warning: TLS: server requested by client is not known.
[1092442.611042] [tempesta fw] Warning: Unrecognized TLS receive return code -0x7900, drop packet

I'm afraid that live normal clients can't access our website.

Scope

There are several points to improve:

• TLS and Tempesta FW layers must print adequate reason for connection break, -0x7900 looks not user friendly. I'd propose to use some static table resolving the codes to human readable messages (probably we should return not so large values in such case or just subtract some constant).
• we should report the error only once, not twice on FW and TLS layers as in the log above
• /proc/tempesta/perfstat must show numbers of successful and and failed TLS handshakes

Testing & documentation

No need any specific documentation or tests.

[voodam]

First two bullets considered to be skipped (not reproduced), third one implemented in #1977.

[krizhanovsky]

I reassigned the issue to myself - let me check what we'll have on the TLS side in production

[krizhanovsky]

I still observe poor TLS error codes in the log, like

[12749.342064] [tempesta tls] Warning: [::ffff:167.248.133.49] Bad TLS record (err -0xFFFFF003)

It'd be good at least to understand on which TLS phase this happens (in the middle of a connection or somewhere in a handshake or even a ClientHello) and what exactly is wrong with the record. If we can realize from the message that for example we don't support some ciphersuite, then that would help a lot.

An example of a multiline error (Tempesta version as of f5929f9)

[11877.720794] [tempesta fw] Warning: Parser error: state=Req_MethodUnknown input(-0)=0x16('^V^C^A') data_len=74 off=0
[11877.722635] [tempesta fw] Warning: failed to parse request: 65.49.1.120
[11877.723983] [tempesta fw] 65.49.1.120 "-" "-  -" 400 0 "-" "-"

[krizhanovsky]

Now I see log records like

[ 1254.092893] [tempesta tls] Warning: bad TLS version 103:1
[ 1254.093951] [tempesta tls] Warning: [::ffff:95.44.176.148] Bad TLS record (err -0xFFFFF003)

or

[ 2982.953400] [tempesta tls] Warning: bad TLS version 69:84
[ 2982.954481] [tempesta tls] Warning: [::ffff:207.154.241.56] Bad TLS record (err -0xFFFFF003)

, which is just broken TLS version, so I'm good with this tracing and we can close the task.