Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Tls errors under ping flood #2117

Open
const-t opened this issue May 9, 2024 · 5 comments · May be fixed by #2150
Open

Tls errors under ping flood #2117

const-t opened this issue May 9, 2024 · 5 comments · May be fixed by #2150
Assignees
Labels
Milestone

Comments

@const-t
Copy link
Contributor

const-t commented May 9, 2024

Scope

Faced weird behavior. I wrote little script for ping flooding, when I running it to test Tempesta, I'm getting a lot of warnings in dmesg about invalid tls processing. However when I added delays between ping frames, all warnings are gone. I tested this script on other implementations. Nginx just blocks me, because it has flood protection. Golang server processes all frames without errors.

commit: 10b38e0

Looks like we don't disconnect client on error in tls protocol.

stats:

Server successful TLS handshakes	: 10
Server failed TLS handshakes		: 33825

log:

[10137.585955] [tempesta tls] Warning: bad TLS version 3:23
[10137.587562] [tempesta tls] Warning: [::ffff:192.168.122.1] Bad TLS record (err -0xFFFFF004)
[10153.840855] net_ratelimit: 14992 callbacks suppressed
[10153.840859] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.843922] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.940461] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.940473] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.945246] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.947550] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.949924] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.952290] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.954743] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10153.957227] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.844526] net_ratelimit: 14689 callbacks suppressed
[10158.844529] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.849920] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.854048] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.858007] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.862118] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.866302] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.870329] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.874353] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.881571] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[10158.886116] [tempesta tls] Warning: [::ffff:192.168.122.1] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)

config:

listen 443 proto=h2;

cache_purge_acl 127.0.0.1;
frang_limits {
   http_strict_host_checking false;
   http_header_cnt 500;
   http_body_len 10485760; #10MB
}

srv_group default {
    server 192.168.122.128:8080 conns_n=1024;
}

tls_certificate /etc/tempesta/tfw-root.crt;
tls_certificate_key /etc/tempesta/tfw-root.key;
tls_match_any_server_name;

vhost debian {
    resp_hdr_set Strict-Transport-Security "max-age=31536000; includeSubDomains";
    proxy_pass default;
}

cache 2;
cache_fulfill * *;
block_action attack reply;
block_action error reply;

http_chain {
  -> debian;
}

Utility:
main.zip
Run: ./flood -address 192.168.122.127:443 -threads 4 -connections 900 -debug 1

@const-t const-t added the bug label May 9, 2024
@krizhanovsky krizhanovsky added the h2 label May 9, 2024
@krizhanovsky krizhanovsky added this to the 0.9 - LA milestone May 9, 2024
@kingluo
Copy link
Contributor

kingluo commented Jun 20, 2024

1. This is a false issue

The tls error comes from the kernel: crypto_aead_decrypt, which returns -EBADMSG and only happens when the OOM reaper already takes effect. That is, it's a side-effect of the kernel under OOM. Even if we have to fix it, the only solution is to avoid OOM.

r = crypto_aead_decrypt(req);

Looks like we don't disconnect client on error in tls protocol.

No, in this case tempesta will FIN (not RST) the connection, so here each error log line appears once per connection.

Therefore, this issue is reasonable in the current implementation.

Instead, we have to add control frame flood protection as soon as possible: #2108.


It's worth noting that, since we bypass the socket API and only do FIN, it's most likely that the client can still send data to us in that connection afterward.

r = T_BAD;

As an aside, in a similar scenario, even if we apply frang rules, if we only send FIN to the client, we will only discard the current skbs in sk->sk_receive_queue, and it is likely that we still need to process subsequent skbs from the client's send direction, which will cause parser errors or other weird things you can see in the logs.

[56708.704451] [tempesta fw] Tempesta FW is ready
[56708.938984] [tempesta fw] Warning: frang: HTTP response body length exceeded for 127.0.0.1: 32510 (lim=1000000)
[56708.944708] [tempesta fw] Warning: frang: HTTP response body length exceeded for 127.0.0.1: 32510 (lim=1000000)
[56708.946966] [tempesta fw] Warning: frang: HTTP response body length exceeded for 127.0.0.1: 32510 (lim=1000000)
[56708.956334] [tempesta fw] Warning: Paired request missing, HTTP Response Splitting attack?
[56708.958363] [tempesta fw] Warning: Paired request missing, HTTP Response Splitting attack?
[56708.958750] [tempesta fw] Warning: Paired request missing, HTTP Response Splitting attack?
[56709.102615] [tdb] Close table 'client0.tdb'
[56709.110280] [tdb] Close table 'sessions0.tdb'
[56709.239456] [tdb] Close table 'filter0.tdb'
[56709.309048] [tempesta fw] exiting...
[56709.435277] [tdb] Shutdown Tempesta DB
[56709.599087] End test:   t_stress.test_slow_read.TestH2SlowRead.test_tcp
p[56763.514977] Start test: t_stress.test_slow_read.TestH2SlowRead.test_tcp
[56763.607055] [tdb] Start Tempesta DB
[56763.630511] net_ratelimit: 350 callbacks suppressed
[56763.630512] [tempesta fw] Initializing Tempesta FW kernel module...
[56763.764604] [tempesta fw] Warning: Vhost tempesta-tech.com doesn't have certificate with matching SAN/CN.
                   Maybe that's fine, but it's worth checking the
                   config - if there is no relations between the
                   names, then host name confusion attack is possible.
[56763.768576] [tempesta fw] Configuration processing is completed.
[56763.872899] [tdb] Opened table /opt/tempesta/db/filter0.tdb: size=16777216 rec_size=20 base=000000003d7eaa06
[56763.880424] [tdb] Opened table /opt/tempesta/db/sessions0.tdb: size=16777216 rec_size=312 base=00000000eb5d19e8
[56763.887227] [tdb] Opened table /opt/tempesta/db/client0.tdb: size=16777216 rec_size=624 base=00000000967942c7
[56764.032465] [tempesta fw] Open listen socket on: 0.0.0.0:443
[56764.088545] [tempesta fw] Tempesta FW is ready
[56764.395696] [tempesta fw] Warning: frang: HTTP response body length exceeded for 127.0.0.1: 32510 (lim=1000000)
[56764.424412] [tempesta fw] Warning: Parser error: state=Resp_HttpVer input(-0)=0x78('xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx') data_len=258 off=0
[56764.424787] [tempesta fw] Warning: Parser error: state=Resp_HttpVer input(-0)=0x78('xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx') data_len=258 off=0
[56764.425148] [tempesta fw] Warning: Parser error: state=Resp_HttpVer input(-0)=0x78('xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx') data_len=258 off=0
[56764.425486] [tempesta fw] Warning: Parser error: state=Resp_HttpVer input(-0)=0x78('xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx') data_len=258 off=0
[56764.425841] [tempesta fw] Warning: Parser error: state=Resp_HttpVer input(-0)=0x78('xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx') data_len=311 off=0

2. Avoid OOM

When OOM already occurs, any remedial measures such as closing the connection are useless. Instead, we must take actions before OOM.

The attack makes sense because the consumption (parsing/processing/acknowledgment) of control frames is much slower than the generation of control frames, so even if the client does not stop reading control frame acks from TCP connections through a small TCP window, or even if there is only one connection for flooding, the server will still consume memory quickly.

Nginx and golang's built-in http2 server use the same strategy to prevent server flooding. When a certain number of control frames waiting for confirmation accumulate, it will immediately close the connection. As mentioned above, they work based on the socket API, so after closing the connection, it is immediate and neat, and will not cause any strange logs afterward.

However when I added delays between ping frames, all warnings are gone.

Because adding the delay will slow down the generation and the consumption will catch up to it, then all is good.

Golang server processes all frames without errors.

No, you will still get an OOM, but golang will avoid that by closing the connection without explicitly telling you what happened via logging.


All the above statements were concluded through patching and testing:

diff --git a/fw/sock.c b/fw/sock.c
index e77b2d68..ceab4e70 100644
--- a/fw/sock.c
+++ b/fw/sock.c
@@ -822,6 +822,7 @@ do {                                                                        \
                r = SS_CALL(connection_recv, conn, skb);

                if (r < 0) {
+                       printk("---> connection_recv\n");
                        T_DBG2("[%d]: Processing error: sk=%pK r=%d\n",
                               smp_processor_id(), sk, r);
                        goto out; /* connection must be dropped */
@@ -1005,6 +1006,7 @@ ss_tcp_data_ready(struct sock *sk)
         * Closing a socket should go through the queue and
         * should be done after all pending data has been sent.
         */
+       printk("---> action=%p, ss_close=%p, ss_shutdown=%p, flags=%d\n", action, ss_close, ss_shutdown, flags);
        if (!(SS_CONN_TYPE(sk) & Conn_Stop) || was_stopped)
                action(sk, flags);
 }
diff --git a/tls/ttls.c b/tls/ttls.c
index 9ccdd874..0a06000f 100644
--- a/tls/ttls.c
+++ b/tls/ttls.c
@@ -937,6 +937,8 @@ __ttls_decrypt(TlsCtx *tls, unsigned char *buf)
        aead_request_set_crypt(req, sg, sg, dec_msglen + TTLS_TAG_LEN,
                               xfrm->iv_dec);
        r = crypto_aead_decrypt(req);
+       if (r != 0)
+               printk("===> crypto_aead_decrypt=%d, -EBADMSG=%d\n", r, -EBADMSG);

        T_DBG3_SL("raw buffer after decryption", sg + 1, sgn - 1, 0,
                  dec_msglen);
@@ -2304,8 +2306,9 @@ ttls_recv(void *tls_data, unsigned char *buf, unsigned int len, unsigned int *re
        }
        *read += io->msglen - io->rlen;
        if ((r = ttls_decrypt(tls, NULL))) {
-               TTLS_WARN(tls, "TLS cannot decrypt msg on state %s, ret=%d%s\n",
-                         tls_state_to_str(tls->state), r,
+               WARN_ON_ONCE(r == -EBADMSG);
+               TTLS_WARN(tls, "ctx=%p, TLS cannot decrypt msg on state %s, ret=%d%s\n",
+                         tls, tls_state_to_str(tls->state), r,
                          r == -EBADMSG ? "(bad ciphertext)" : "");
                return r;
        }
@@ -2354,6 +2357,7 @@ EXPORT_SYMBOL(ttls_key_cert_free);
 void
 ttls_ctx_clear(TlsCtx *tls)
 {
+       printk("close ctx=%p\n", tls);
        ttls_handshake_free(tls->hs);

        ttls_cipher_free(&tls->xfrm.cipher_ctx_enc);

logs:

[  112.205412] ---> connection_recv
[  112.205492] ---> action=000000000e623f45, ss_close=00000000c7751576, ss_shutdown=000000000e623f45, flags=1
[  112.205725] ksoftirqd/1: page allocation failure: order:0, mode:0xa20(GFP_ATOMIC), nodemask=(null),cpuset=/,mems_allowed=0
[  112.205758] CPU: 1 PID: 20 Comm: ksoftirqd/1 Kdump: loaded Tainted: G           OE     5.10.35+ #2
[  112.205778] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014
[  112.205803] Call Trace:
[  112.205817]  dump_stack+0x70/0x8b
[  112.205828]  warn_alloc.cold+0x78/0xdc
[  112.205842]  __alloc_pages_slowpath.constprop.0+0xd99/0xdc0
[  112.205856]  __alloc_pages_nodemask+0x30f/0x340
[  112.205868]  page_frag_alloc+0x165/0x1a0
[  112.205880]  netdev_alloc_frag+0x6c/0x90
[  112.205894]  e1000_alloc_rx_buffers+0x9d/0x3d0 [e1000]
[  112.205908]  e1000_clean_rx_irq+0x311/0x510 [e1000]
[  112.205956]  e1000_clean+0x259/0x5f0 [e1000]
[  112.205969]  net_rx_action+0x13b/0x3c0
[  112.205980]  __do_softirq+0xd5/0x28b
[  112.205991]  run_ksoftirqd+0x2b/0x40
[  112.206001]  smpboot_thread_fn+0xd0/0x170
[  112.206011]  kthread+0x130/0x150
[  112.206021]  ? smpboot_register_percpu_thread+0xe0/0xe0
[  112.206033]  ? kthread_associate_blkcg+0xb0/0xb0
[  112.206081]  ret_from_fork+0x22/0x30
...
[  112.253518] ===> crypto_aead_decrypt=-74, -EBADMSG=-74
[  112.253878] ------------[ cut here ]------------
[  112.254231] WARNING: CPU: 2 PID: 26 at /home/kingluo/tempesta/tls/ttls.c:2309 ttls_recv+0x714/0x880 [tempesta_tls]
...
[  112.264549] Call Trace:
[  112.264972]  ss_skb_process+0x81/0x140 [tempesta_fw]
[  112.265377]  ? ttls_handle_alert+0x40/0x40 [tempesta_tls]
[  112.265796]  tfw_tls_connection_recv+0xd4/0x420 [tempesta_fw]
[  112.266171]  ? tcp_xmit_retransmit_queue.part.0+0x3f/0x350
[  112.266562]  ss_tcp_process_data+0x1de/0x3c0 [tempesta_fw]
[  112.266986]  ss_tcp_data_ready+0x54/0xd0 [tempesta_fw]
[  112.267361]  tcp_data_ready+0x2b/0xd0
[  112.267719]  tcp_data_queue+0x7b5/0xdb0
[  112.268068]  tcp_rcv_established+0x254/0x690
[  112.268416]  tcp_v4_do_rcv+0x140/0x200
[  112.268752]  tcp_v4_rcv+0xc95/0xdf0
[  112.269082]  ip_protocol_deliver_rcu+0x30/0x1b0
[  112.269400]  ip_local_deliver_finish+0x48/0x60
[  112.269699]  ip_local_deliver+0xf8/0x110
[  112.269981]  ? ip_protocol_deliver_rcu+0x1b0/0x1b0
[  112.270262]  ip_rcv_finish+0x87/0xa0
[  112.270548]  ip_rcv+0xce/0xe0
[  112.270831]  ? ip_rcv_finish_core.constprop.0+0x430/0x430
[  112.271234]  __netif_receive_skb_one_core+0x86/0xa0
[  112.271533]  __netif_receive_skb+0x18/0x60
[  112.271819]  process_backlog+0x9e/0x170
[  112.272108]  net_rx_action+0x13b/0x3c0
...
[  112.274952] ---> connection_recv
[  112.275215] ---> action=000000000e623f45, ss_close=00000000c7751576, ss_shutdown=000000000e623f45, flags=1
[  112.276488] ===> crypto_aead_decrypt=-74, -EBADMSG=-74
[  112.276763] [tempesta tls] Warning: [::ffff:192.168.2.2] ctx=00000000549058e2, TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)


A small mistake in the client test script: the ping_flood() should be replaced with go ping_flood(), otherwise, no parallel connections created.

@const-t
Copy link
Contributor Author

const-t commented Jun 20, 2024

I still can reproduce the issue, you went wrong way. First of all:

ping_flood() should be replaced with go ping_flood()

no, it's must not be patched, it's PoC please use it as is. Otherwise you will got OOM, definitely. Yes, it's looks strange but I hacked this way just to show the error in Tempesta.

Memory consumption about 2.5GB of 8GB, it's pretty small. In the dmesg I don't have any warnings about OOM or buddy exhausting. Complete dmesg log is attached.

I've one assumption, maybe you testing it inside single VM. If so, please, try to run the script on the host OS or from other VM.

[   51.353135] [tempesta fw] Tempesta FW is ready
[   60.100821] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.114396] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.115287] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.118019] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.120523] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.123013] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.123825] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.124648] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.125466] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   60.137345] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.124474] net_ratelimit: 856 callbacks suppressed
[   65.124894] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.125904] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.185493] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.187398] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.188440] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.286053] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.290098] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.310963] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.314132] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[   65.317406] [tempesta tls] Warning: [::ffff:192.168.122.128] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)

@kingluo
Copy link
Contributor

kingluo commented Jun 20, 2024

no, it's must not be patched, it's PoC please use it as is. Otherwise you will got OOM, definitely. Yes, it's looks strange but I hacked this way just to show the error in Tempesta.

That's a mistake definitely, because then your connection argument doesn't take effect actually, i.e. it blocks on the first connection, then how many clients is how many connections.

In fact, I also test with your original script, only one client one connection, if no delay, it will make tempesta consume memory constantly, although it's slower.

./ping_flood -address 192.168.2.1:443 -threads 1 -connections 1 -debug 1

Memory consumption about 2.5GB of 8GB, it's pretty small. In the dmesg I don't have any warnings about OOM or buddy exhausting. Complete dmesg log is attached.

As long as no delay, the memory will increase constantly. It will not stop at some amount. And I cannot reproduce your error message without OOM.

I've one assumption, maybe you testing it inside single VM. If so, please, try to run the script on the host OS or from other VM.

No, I tried both one VM or two VM cases, and both have the same result. The only difference is one VM case will has slow memory increase rate because the consumption of control frame in tempesta is faster than the two VM cases.

@const-t
Copy link
Contributor Author

const-t commented Jun 20, 2024

As long as no delay, the memory will increase constantly. It will not stop at some amount. And I cannot reproduce your error message without OOM.

Of course it will, if you "fix" it. Basically it must

blocks on the first connection

it's desired behavior just for PoC.

@kingluo
Copy link
Contributor

kingluo commented Jun 24, 2024

ping

step16: the last possible partial ssl record may lost

while ((skb = ss_skb_dequeue(&skb_head))) {

step17: sk->sk_receive_queue is not purged

if (r < 0)


The root cause of the tls error is that si_wq (which has a default budget of 10, but even 1,000,000 is not enough to flood a single connection) cannot tolerate the high rate of ping acks being sent and returns -EBUSY, which causes tfw_tls_connection_recv to return TBAD, and then ss_tcp_process_skb frees the current skb list (probably from unrolling), which may contain a partial SSL record. Because we don't flush the sk->sk_receive_queue, and shutdown (FIN) is asynchronous, it has a high chance of servicing pending or upcoming packets in that connection in an indeterminate time window and reporting errors caused by incomplete parsed SSL records or even invalid parsed SSL headers.

It's impossible to come up with a perfect solution in the current implementation because we don't have socket buffer-based back pressure (#498) in the client TCP connection.

  • Workaround 1: return RST on error
diff --git a/tls/ttls.c b/tls/ttls.c
index 9ccdd874..f526b004 100644
--- a/tls/ttls.c
+++ b/tls/ttls.c
@@ -2307,7 +2307,7 @@ ttls_recv(void *tls_data, unsigned char *buf, unsigned int len, unsigned int *re
                TTLS_WARN(tls, "TLS cannot decrypt msg on state %s, ret=%d%s\n",
                          tls_state_to_str(tls->state), r,
                          r == -EBADMSG ? "(bad ciphertext)" : "");
-               return r;
+               return T_BLOCK_WITH_RST;
        }

        if (io->msgtype == TTLS_MSG_ALERT) {

debug logs:

[ 4911.007592] [tempesta fw] Tempesta FW is ready
[ 4912.759596] [tempesta fw] Warning: sock_srv: cannot establish connection for 127.0.0.1:8080: 6 tries, keep trying...
[ 4916.887788] [tempesta fw] Warning: ---> tfw_connection_send=-16
[ 4916.888042] ----> ctx->state=5
[ 4916.888269] [tempesta fw] Warning: ------------> tfw_h2_frame_recv failed, r=-16
[ 4916.888504] [tempesta fw] Warning: ------------> tfw_http_msg_process failed, r=-16
[ 4916.888866] [tempesta fw] Warning: ----------> connection_recv failed, r=-4089
[ 4916.967939] [tempesta fw] Warning: Attempt to send on inactive socket 000000004950b198, r=-9
[ 4916.968235] [tempesta fw] Warning: ---> tfw_connection_send=-9
[ 4916.968529] [tempesta fw] Warning: ------------> tfw_h2_frame_recv failed, r=-9
[ 4916.968792] [tempesta fw] Warning: ------------> tfw_http_msg_process failed, r=-9
[ 4916.969199] [tempesta fw] Warning: ----------> connection_recv failed, r=-4089
[ 4916.969563] [tempesta fw] Warning: Attempt to send on inactive socket 000000004950b198, r=-9
[ 4917.437696] -----> may discard unread partial ssl records!
[ 4917.451712] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[ 4917.452081] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[ 4917.452423] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[ 4917.452771] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[ 4917.453048] -----> may discard unread partial ssl records!
[ 4917.453453] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)
[ 4917.453769] TLS cannot decrypt msg on state Handshake Over, ret=-74(bad ciphertext)

There are no bugs with KTLS and kernel TCP/IP, as we can demonstrate it using a simple python script that serves h2 traffic in a single thread using openssl and KTLS. Also, the throughput is 20x higher than tempesta, with no significant impact on memory usage.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants