tempesta-tech
Sticky cookies doesn't work over h2
Scope
In HTTP/1.x Cookie: header was singular: it could present in the request only once. If more than one cookie are passed to server, all of them are stored in in the same header.
In HTTP/2 it was revised. Non-usual delimiter between values (; instead of ,) cause problems to update only one cookie between requests.
So both cookie codings are valid:
cookie: a=b; c=d; e=f
cookie: a=b
cookie: c=d
cookie: e=f
Browsers prefer the second case. And that cause Tempesta to crash on BUG_ON() statement. When sticky cookie is enabled, the chain of functions is called: tfw_http_sticky_get_req() -> tfw_http_msg_clnthdr_val() -> __h2_msg_hdr_val() -> BUG_ON(TFW_STR_DUP(hdr)).
The http_sess code must be updated to support duplicated Cookie headers on h2 protocol.
Steps to reproduce:
- populate several (>>1) permanent cookies for protected uri
- try to reach the uri via Tempesta over h2 protocol
- enjoy the crash
Testing
Test sticky cookie via h2 protocol, when multiple cookies are send by client.
Caught a new sporadic crash, if sticky cookie module is enabled:
[ 2254.580289] BUG: unable to handle kernel NULL pointer dereference at 0000000000000040
[ 2254.587035] IP: frang_http_req_handler+0xa2/0x4f0 [tempesta_fw]
[ 2254.588551] PGD 0 P4D 0
[ 2254.589194] Oops: 0000 [#1] SMP PTI
[ 2254.590854] Modules linked in: tempesta_fw(O) tempesta_db(O) tempesta_tls(O) tempesta_lib(O) sha256_ssse3 sha512_ssse3 sha512_generic ccm kvm_intel snd_hda_codec_generic kvm irqbypass iTCO_wdt crct10dif_pclmul iTCO_vendor_support snd_hda_intel crc32_pclmul snd_hda_codec snd_hda_core snd_hwdep snd_pcm ghash_clmulni_intel snd_timer evdev binfmt_misc serio_raw pcspkr snd soundcore sg virtio_balloon virtio_gpu virtio_console ttm lpc_ich mfd_core drm_kms_helper drm shpchp button ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 fscrypto ecb aesni_intel crypto_simd cryptd glue_helper aes_x86_64 crc32c_generic sr_mod cdrom virtio_blk virtio_net crc32c_intel ahci psmouse libahci sym53c8xx libata scsi_transport_spi i2c_i801 ehci_pci uhci_hcd scsi_mod ehci_hcd virtio_pci virtio_ring virtio usbcore usb_common
[ 2254.615815] [last unloaded: tempesta_lib]
[ 2254.616637] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G B W O 4.14.0-tempesta-kmemleak-amd64 #1 Debian 4.14.32-tfw7-1
[ 2254.618417] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS ?-20191223_100556-anatol 04/01/2014
[ 2254.619948] task: ffffffff9c012480 task.stack: ffffffff9c000000
[ 2254.621911] RIP: 0010:frang_http_req_handler+0xa2/0x4f0 [tempesta_fw]
[ 2254.624385] RSP: 0018:ffff958d654037f0 EFLAGS: 00010286
[ 2254.626200] RAX: 0000000000000000 RBX: ffff958d4f405048 RCX: ffff958d3eb26600
[ 2254.632141] RDX: 0000000000000000 RSI: 00000000fffffe01 RDI: ffffffffc07a71bc
[ 2254.636365] RBP: 0000000000000000 R08: 0000000000000002 R09: 0000000000000002
[ 2254.643623] R10: 0000000000000002 R11: 0000000000000002 R12: ffff958d65403970
[ 2254.646376] R13: ffff958d3cc3b020 R14: ffff958d34e5f5b0 R15: ffff958d3bb78000
[ 2254.649972] FS: 0000000000000000(0000) GS:ffff958d65400000(0000) knlGS:0000000000000000
[ 2254.651293] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2254.652232] CR2: 0000000000000040 CR3: 000000006a40a001 CR4: 00000000003606f0
[ 2254.654320] Call Trace:
[ 2254.655330] <IRQ>
[ 2254.656235] __gfsm_fsm_exec+0x56/0x90 [tempesta_fw]
[ 2254.658118] tfw_gfsm_move+0x14b/0x180 [tempesta_fw]
[ 2254.659267] tfw_http_msg_process_generic+0x5a4/0xd10 [tempesta_fw]
[ 2254.662075] ? tfw_h2_conn_terminate_close+0x40/0x40 [tempesta_fw]
[ 2254.664324] ? ss_skb_process+0x11b/0x140 [tempesta_fw]
[ 2254.670857] tfw_h2_frame_process+0x21b/0x490 [tempesta_fw]
[ 2254.673264] tfw_http_msg_process+0xb6/0xc0 [tempesta_fw]
[ 2254.675674] __gfsm_fsm_exec+0x56/0x90 [tempesta_fw]
[ 2254.677038] tfw_gfsm_move+0x14b/0x180 [tempesta_fw]
[ 2254.679440] tfw_tls_msg_process+0x301/0x4d0 [tempesta_fw]
[ 2254.682921] ? ip_output+0x71/0xe0
[ 2254.685203] ? ip_queue_xmit+0x5c/0x3b0
[ 2254.687821] __gfsm_fsm_exec+0x56/0x90 [tempesta_fw]
[ 2254.689326] tfw_connection_recv+0x41/0x60 [tempesta_fw]
[ 2254.692427] ? tfw_connection_send+0x30/0x30 [tempesta_fw]
[ 2254.697701] ss_tcp_process_data+0x1ea/0x480 [tempesta_fw]
[ 2254.702204] ? mod_timer+0x177/0x3b0
[ 2254.703354] ss_tcp_data_ready+0x43/0x90 [tempesta_fw]
[ 2254.704283] tcp_rcv_established+0x4d2/0x570
[ 2254.705208] tcp_v4_do_rcv+0x129/0x1d0
[ 2254.706244] tcp_v4_rcv+0x947/0xa50
[ 2254.707029] ip_local_deliver_finish+0x9a/0x1c0
[ 2254.707765] ip_local_deliver+0x6b/0xe0
[ 2254.708417] ? tcp_v4_early_demux+0x112/0x150
[ 2254.709146] ? ip_rcv_finish+0x17a/0x400
[ 2254.709781] ip_rcv+0x289/0x3c0
[ 2254.710325] ? inet_del_offload+0x40/0x40
[ 2254.711160] __netif_receive_skb_core+0x84f/0xb30
[ 2254.712254] ? enqueue_entity+0x110/0x7a0
[ 2254.713707] ? process_backlog+0xa3/0x160
[ 2254.714322] process_backlog+0xa3/0x160
[ 2254.715024] net_rx_action+0x28e/0x3f0
[ 2254.715635] ? try_to_wake_up+0x54/0x490
[ 2254.716351] __do_softirq+0x10f/0x2a8
[ 2254.716985] irq_exit+0xae/0xb0
[ 2254.717493] call_function_single_interrupt+0x7d/0x90
[ 2254.718266] </IRQ>
[ 2254.718593] RIP: 0010:native_safe_halt+0x2/0x10
[ 2254.719389] RSP: 0018:ffffffff9c003e98 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff04
[ 2254.720585] RAX: ffffffff9b69a7a0 RBX: ffffffff9c012480 RCX: 0000000000000000
[ 2254.724073] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 2254.726204] RBP: 0000000000000000 R08: 0000000000000002 R09: ffffffff9c008528
[ 2254.727833] R10: 0000000000025b4e R11: 0000000000000000 R12: ffffffff9c012480
[ 2254.730290] R13: ffffffff9c012480 R14: 0000000000000000 R15: 0000000000000000
[ 2254.732368] ? __sched_text_end+0x3/0x3
[ 2254.733240] default_idle+0x1a/0xf0
[ 2254.734309] do_idle+0x16e/0x1f0
[ 2254.734797] cpu_startup_entry+0x6f/0x80
[ 2254.735299] start_kernel+0x467/0x487
[ 2254.735782] secondary_startup_64+0xa5/0xb0
[ 2254.736313] Code: 5f c3 49 89 fe 49 89 f4 e8 fc 0d fb ff 48 85 c0 49 89 c7 0f 84 2a 03 00 00 48 85 db 4d 8b 6c 24 08 0f 84 42 03 00 00 49 8b 45 40 <4c> 3b 68 40 0f 85 36 03 00 00 49 8b 85 f0 00 00 00 48 85 c0 0f
[ 2254.739507] RIP: frang_http_req_handler+0xa2/0x4f0 [tempesta_fw] RSP: ffff958d654037f0
[ 2254.740911] CR2: 0000000000000040
Even had to suppress the issue in 1c041ea517f8bc2fab98e4116954476a0cd607df
Same or similar problem is alive.
When I turn on cookie enforce and try to send request with no Cookie header or with many Cookie headers, connection did not closed with error.
Tempesta:
listen 127.0.0.4:8765 proto=h2;
sticky {
cookie name=__test enforce;
}
srv_group default {
server ${server_ip}:8000;
}
vhost tempesta-cat {
proxy_pass default;
}
tls_match_any_server_name;
tls_certificate ${tempesta_workdir}/tempesta.crt;
tls_certificate_key ${tempesta_workdir}/tempesta.key;
cache 0;
cache_fulfill * *;
block_action attack reply;
http_chain {
-> tempesta-cat;
}
Backend
'id': 'nginx',
'type': 'nginx',
'port': '8000',
'status_uri': 'http://${server_ip}:8000/nginx_status',
'config': """
pid ${pid};
worker_processes auto;
events {
worker_connections 1024;
use epoll;
}
http {
keepalive_timeout ${server_keepalive_timeout};
keepalive_requests ${server_keepalive_requests};
sendfile on;
tcp_nopush on;
tcp_nodelay on;
open_file_cache max=1000;
open_file_cache_valid 30s;
open_file_cache_min_uses 2;
open_file_cache_errors off;
error_log /dev/null emerg;
access_log off;
server {
listen ${server_ip}:8000;
location / {
return 200;
}
location /nginx_status {
stub_status on;
}
}
}
"""
Client:
curl -Ikf -v --http2 https://127.0.0.4:8765/ -H "Host: tempesta-tech.com:8765" -H "Cookie: name1=value1" -H "Cookie: name2=value2
curl -Ikf -v --http2 https://127.0.0.4:8765/ -H "Host: tempesta-tech.com:8765"
Same result for both clients
Exception: Remote error: Error running command 'curl -Ikf -v --http2 https://127.0.0.4:8765/ -H "Host: tempesta-tech.com:8765"' on localhost, stdout = b'', stderr = b'* Trying 127.0.0.4:8765...\n* TCP_NODELAY set\n % Total % Received % Xferd Average Speed Time Time Time Current\n Dload Upload Total Spent Left Speed\n\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Connected to 127.0.0.4 (127.0.0.4) port 8765 (#0)\n* ALPN, offering h2\n* ALPN, offering http/1.1\n* successfully set certificate verify locations:\n* CAfile: /etc/ssl/certs/ca-certificates.crt\n CApath: /etc/ssl/certs\n} [5 bytes data]\n* TLSv1.3 (OUT), TLS handshake, Client hello (1):\n} [512 bytes data]\n* TLSv1.3 (IN), TLS handshake, Server hello (2):\n{ [100 bytes data]\n* TLSv1.2 (IN), TLS handshake, Certificate (11):\n{ [620 bytes data]\n* TLSv1.2 (IN), TLS handshake, Server key exchange (12):\n{ [147 bytes data]\n* TLSv1.2 (IN), TLS handshake, Server finished (14):\n{ [4 bytes data]\n* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):\n} [70 bytes data]\n* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):\n} [1 bytes data]\n* TLSv1.2 (OUT), TLS handshake, Finished (20):\n} [16 bytes data]\n* TLSv1.2 (IN), TLS handshake, Finished (20):\n{ [16 bytes data]\n* SSL connection using TLSv1.2 / ECDHE-ECDSA-AES128-GCM-SHA256\n* ALPN, server accepted to use h2\n* Server certificate:\n* subject: C=US; ST=Washington; L=Seattle; O=Tempesta Technologies Inc.; OU=Testing; CN=tempesta-tech.com; [email protected]\n* start date: Aug 12 20:27:17 2022 GMT\n* expire date: Aug 13 20:27:17 2023 GMT\n* issuer: C=US; ST=Washington; L=Seattle; O=Tempesta Technologies Inc.; OU=Testing; CN=tempesta-tech.com; [email protected]\n* SSL certificate verify result: self signed certificate (18), continuing anyway.\n* Using HTTP2, server supports multi-use\n* Connection state changed (HTTP/2 confirmed)\n* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0\n} [5 bytes data]\n* Using Stream ID: 1 (easy handle 0x559aa5aef2f0)\n} [5 bytes data]\n> HEAD / HTTP/2\r\n> Host: tempesta-tech.com:8765\r\n> user-agent: curl/7.68.0\r\n> accept: */*\r\n> \r\n{ [5 bytes data]\n* Connection state changed (MAX_CONCURRENT_STREAMS == 4294967295)!\n} [5 bytes data]\n* http2 error: Invalid HTTP header field was received: frame type: 1, stream: 1, name: [location], value: [https://10\x97\xa1K\x97\xff\xff\x11]\n} [5 bytes data]\n* HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)\n* stopped the pause stream!\n\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0\n* Connection #0 to host 127.0.0.4 left intact\ncurl: (92) HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)\n'
