tempesta
tempesta copied to clipboard
Tempesta fails with concurrent or several h2 PUT requests
Tempesta fails when:
- received several requests
curl -k --http2-prior-knowledge -X PUT -d '0' https://127.0.0.1:443/[1-5] - concurrent sending of requests
DMESG
[ 9101.347536] ------------[ cut here ]------------
[ 9101.347556] WARNING: CPU: 3 PID: 13008 at /root/tempesta/fw/hpack.c:1243 tfw_hpack_decode+0x1c5f/0x1c70 [tempesta_fw]
[ 9101.347557] Modules linked in: tempesta_fw(OE) tempesta_db(OE) tempesta_tls(OE) tempesta_lib(OE) nfnetlink_queue nfnetlink_log nfnetlink cfg80211 sha256_ssse3 sha512_ssse3 rfcomm bnep vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport vsock nls_iso8859_1 intel_rapl_msr intel_rapl_common crct10dif_pclmul ghash_clmulni_intel aesni_intel snd_ens1371 snd_ac97_codec crypto_simd gameport cryptd ac97_bus glue_helper snd_pcm btusb btrtl snd_seq_midi btbcm snd_seq_midi_event btintel snd_rawmidi bluetooth snd_seq snd_seq_device snd_timer joydev input_leds snd ecdh_generic ecc serio_raw vmw_balloon vmw_vmci soundcore sch_fq_codel vmwgfx mac_hid ttm drm_kms_helper cec rc_core fb_sys_fops syscopyarea sysfillrect sysimgblt ipmi_devintf ipmi_msghandler drm msr parport_pc ppdev lp parport pstore_blk ramoops reed_solomon pstore_zone efi_pstore ip_tables x_tables autofs4 hid_generic usbhid hid mptspi mptscsih mptbase psmouse ahci crc32_pclmul e1000 libahci scsi_transport_spi i2c_piix4
[ 9101.347598] pata_acpi [last unloaded: tempesta_lib]
[ 9101.347601] CPU: 3 PID: 13008 Comm: curl Kdump: loaded Tainted: G W OE 5.10.35+ #1
[ 9101.347602] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
[ 9101.347610] RIP: 0010:tfw_hpack_decode+0x1c5f/0x1c70 [tempesta_fw]
[ 9101.347611] Code: 89 cf 48 8b 45 a8 4c 89 ee 48 29 d7 48 c1 e6 0a 4c 89 c2 4c 01 cf 48 01 c6 48 c1 e7 05 48 01 c7 e8 76 ad d5 ff e9 ab fc ff ff <0f> 0b 41 bc fe ff ff ff e9 c4 ec ff ff 0f 1f 40 00 0f 1f 44 00 00
[ 9101.347612] RSP: 0018:ffffbc7640548850 EFLAGS: 00010216
[ 9101.347613] RAX: 0000000000000042 RBX: 0000000000000029 RCX: ffffa04df425b089
[ 9101.347614] RDX: 0000000000000054 RSI: 0000000000005550 RDI: ffffa04df3e2b027
[ 9101.347614] RBP: ffffbc76405488d8 R08: ffffa04df425b087 R09: 0000000000000040
[ 9101.347615] R10: ffffa04df3e2b020 R11: 0000000000000570 R12: 00000000ffffffff
[ 9101.347616] R13: ffffa04dd7d02ec0 R14: ffffa04df15b6020 R15: ffffa04dcfe53098
[ 9101.347617] FS: 00007f5130ec3f80(0000) GS:ffffa04ff5ec0000(0000) knlGS:0000000000000000
[ 9101.347617] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 9101.347618] CR2: 0000558559fa5e58 CR3: 00000000311a0001 CR4: 0000000000770ee0
[ 9101.347625] PKRU: 55555554
[ 9101.347626] Call Trace:
[ 9101.347627] <IRQ>
[ 9101.347636] tfw_h2_parse_req+0x51/0x1c0 [tempesta_fw]
[ 9101.347642] ss_skb_process+0xf6/0x140 [tempesta_fw]
[ 9101.347647] ? tfw_http_parse_req+0xe190/0xe190 [tempesta_fw]
[ 9101.347653] ? tfw_http_parse_req+0xe190/0xe190 [tempesta_fw]
[ 9101.347658] tfw_http_req_process+0x7f/0x960 [tempesta_fw]
[ 9101.347661] ? alloc_pages_current+0x87/0xe0
[ 9101.347663] ? __get_free_pages+0x11/0x40
[ 9101.347668] ? tfw_pool_alloc_pages+0x47/0x50 [tempesta_fw]
[ 9101.347673] ? __tfw_pool_new+0x2d/0x70 [tempesta_fw]
[ 9101.347677] tfw_http_msg_process_generic+0x197/0x670 [tempesta_fw]
[ 9101.347682] ? ss_skb_chop_head_tail+0xbb/0x1d0 [tempesta_fw]
[ 9101.347687] ? ss_skb_process+0xf6/0x140 [tempesta_fw]
[ 9101.347691] tfw_h2_frame_process+0x308/0x440 [tempesta_fw]
[ 9101.347696] tfw_http_msg_process+0x42/0x50 [tempesta_fw]
[ 9101.347700] tfw_connection_recv+0x59/0xa0 [tempesta_fw]
[ 9101.347704] tfw_tls_connection_recv+0x19d/0x380 [tempesta_fw]
[ 9101.347709] ss_tcp_process_data+0x1e7/0x3f0 [tempesta_fw]
[ 9101.347714] ss_tcp_data_ready+0x44/0xb0 [tempesta_fw]
[ 9101.347717] tcp_data_ready+0x2b/0xd0
[ 9101.347718] tcp_rcv_established+0x5a7/0x670
[ 9101.347720] tcp_v4_do_rcv+0x140/0x200
[ 9101.347721] tcp_v4_rcv+0xcfd/0xe10
[ 9101.347722] ip_protocol_deliver_rcu+0x30/0x1b0
[ 9101.347723] ip_local_deliver_finish+0x48/0x60
[ 9101.347724] ip_local_deliver+0x72/0x110
[ 9101.347729] ? tfw_ipv4_nf_hook+0xb9/0x130 [tempesta_fw]
[ 9101.347730] ip_rcv_finish+0x87/0xa0
[ 9101.347731] ip_rcv+0xcc/0xe0
[ 9101.347732] ? ip_rcv_finish_core.isra.0+0x420/0x420
[ 9101.347734] __netif_receive_skb_one_core+0x88/0xa0
[ 9101.347735] __netif_receive_skb+0x18/0x60
[ 9101.347736] process_backlog+0xa9/0x160
[ 9101.347737] net_rx_action+0x13e/0x390
[ 9101.347739] __do_softirq+0xd9/0x291
[ 9101.347741] asm_call_irq_on_stack+0xf/0x20
[ 9101.347742] </IRQ>
[ 9101.347743] do_softirq_own_stack+0x3d/0x50
[ 9101.347745] do_softirq.part.0+0x46/0x50
[ 9101.347746] __local_bh_enable_ip+0x50/0x60
[ 9101.347747] ip_finish_output2+0x1ab/0x590
[ 9101.347749] ? __cgroup_bpf_run_filter_skb+0x3c3/0x3d0
[ 9101.347751] __ip_finish_output+0xd8/0x220
[ 9101.347751] ip_finish_output+0x2d/0xb0
[ 9101.347752] ip_output+0x7a/0x100
[ 9101.347753] ? ip_finish_output+0x2d/0xb0
[ 9101.347754] ip_local_out+0x3d/0x50
[ 9101.347755] __ip_queue_xmit+0x17a/0x470
[ 9101.347757] ? get_page_from_freelist+0xed8/0x1100
[ 9101.347758] ip_queue_xmit+0x15/0x20
[ 9101.347759] __tcp_transmit_skb+0xa94/0xc90
[ 9101.347760] tcp_write_xmit+0x453/0x1350
[ 9101.347761] __tcp_push_pending_frames+0x37/0x100
[ 9101.347762] tcp_push+0xfc/0x100
[ 9101.347764] tcp_sendmsg_locked+0xd36/0xe70
[ 9101.347765] tcp_sendmsg+0x2d/0x50
[ 9101.347766] inet_sendmsg+0x43/0x70
[ 9101.347768] sock_sendmsg+0x5e/0x70
[ 9101.347769] sock_write_iter+0x93/0xf0
[ 9101.347771] new_sync_write+0x192/0x1b0
[ 9101.347772] vfs_write+0x1ca/0x280
[ 9101.347773] ksys_write+0xb1/0xe0
[ 9101.347774] __x64_sys_write+0x1a/0x20
[ 9101.347775] do_syscall_64+0x38/0x90
[ 9101.347776] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 9101.347778] RIP: 0033:0x7f51322e62f7
[ 9101.347779] Code: 75 05 48 83 c4 58 c3 e8 f7 33 ff ff 0f 1f 80 00 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
[ 9101.347779] RSP: 002b:00007ffddf5db4d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 9101.347780] RAX: ffffffffffffffda RBX: 0000000000000036 RCX: 00007f51322e62f7
[ 9101.347781] RDX: 0000000000000036 RSI: 0000558559fa1da3 RDI: 0000000000000005
[ 9101.347781] RBP: 0000558559f60ad0 R08: 0000000000000001 R09: 0000000000000008
[ 9101.347782] R10: 0000558559fa1da5 R11: 0000000000000246 R12: 0000558559fa1da3
[ 9101.347782] R13: 0000000000000036 R14: 0000558559f5ee20 R15: 0000000000000000
[ 9101.347784] ---[ end trace 50b1b7ebb7b42b2f ]---
[ 9101.347785] net_ratelimit: 3923 callbacks suppressed
[ 9101.347786] [tempesta fw] Warning: failed to parse request: 127.0.0.1
[ 9101.347792] ------------[ cut here ]------------
[ 9101.347798] WARNING: CPU: 3 PID: 13008 at /root/tempesta/fw/http_stream.c:89 tfw_h2_stream_fsm+0x12d/0x2b0 [tempesta_fw]
[ 9101.347798] Modules linked in: tempesta_fw(OE) tempesta_db(OE) tempesta_tls(OE) tempesta_lib(OE) nfnetlink_queue nfnetlink_log nfnetlink cfg80211 sha256_ssse3 sha512_ssse3 rfcomm bnep vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport vsock nls_iso8859_1 intel_rapl_msr intel_rapl_common crct10dif_pclmul ghash_clmulni_intel aesni_intel snd_ens1371 snd_ac97_codec crypto_simd gameport cryptd ac97_bus glue_helper snd_pcm btusb btrtl snd_seq_midi btbcm snd_seq_midi_event btintel snd_rawmidi bluetooth snd_seq snd_seq_device snd_timer joydev input_leds snd ecdh_generic ecc serio_raw vmw_balloon vmw_vmci soundcore sch_fq_codel vmwgfx mac_hid ttm drm_kms_helper cec rc_core fb_sys_fops syscopyarea sysfillrect sysimgblt ipmi_devintf ipmi_msghandler drm msr parport_pc ppdev lp parport pstore_blk ramoops reed_solomon pstore_zone efi_pstore ip_tables x_tables autofs4 hid_generic usbhid hid mptspi mptscsih mptbase psmouse ahci crc32_pclmul e1000 libahci scsi_transport_spi i2c_piix4
[ 9101.347819] pata_acpi [last unloaded: tempesta_lib]
[ 9101.347821] CPU: 3 PID: 13008 Comm: curl Kdump: loaded Tainted: G W OE 5.10.35+ #1
[ 9101.347822] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
[ 9101.347826] RIP: 0010:tfw_h2_stream_fsm+0x12d/0x2b0 [tempesta_fw]
[ 9101.347827] Code: 89 a0 01 00 00 0f 0b 83 f8 06 74 6b 83 f8 07 75 f4 45 31 c0 41 80 fd 02 0f 84 56 ff ff ff 41 80 fd 09 0f 85 46 ff ff ff eb 8c <0f> 0b 41 b8 03 00 00 00 e9 3d ff ff ff 41 b8 03 00 00 00 e9 3c ff
[ 9101.347828] RSP: 0018:ffffbc7640548530 EFLAGS: 00010293
[ 9101.347829] RAX: 0000000000000002 RBX: ffffa04dd7d02ec0 RCX: 0000000000000001
[ 9101.347829] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffffa04dd7d02ef0
[ 9101.347830] RBP: ffffbc7640548560 R08: ffffbc764054857c R09: 0000000000000000
[ 9101.347830] R10: 0000000000000002 R11: 0000000000000000 R12: ffffa04dd7d02ef0
[ 9101.347831] R13: 0000000000000001 R14: 0000000000000001 R15: 0000000000000001
[ 9101.347832] FS: 00007f5130ec3f80(0000) GS:ffffa04ff5ec0000(0000) knlGS:0000000000000000
[ 9101.347832] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 9101.347833] CR2: 0000558559fa5e58 CR3: 00000000311a0001 CR4: 0000000000770ee0
[ 9101.347839] PKRU: 55555554
[ 9101.347839] Call Trace:
[ 9101.347840] <IRQ>
[ 9101.347844] tfw_h2_stream_id_close+0xe7/0x110 [tempesta_fw]
[ 9101.347849] tfw_h2_prep_resp+0x95/0x310 [tempesta_fw]
[ 9101.347850] ? alloc_pages_current+0x87/0xe0
[ 9101.347855] tfw_h2_send_resp+0x5c/0xb0 [tempesta_fw]
[ 9101.347859] tfw_h2_send_err_resp+0x9a/0xc0 [tempesta_fw]
[ 9101.347864] tfw_http_cli_error_resp_and_log+0x3cd/0x440 [tempesta_fw]
[ 9101.347869] ? tfw_http_parse_req+0xe190/0xe190 [tempesta_fw]
[ 9101.347874] tfw_http_req_process+0xf6/0x960 [tempesta_fw]
[ 9101.347875] ? alloc_pages_current+0x87/0xe0
[ 9101.347876] ? __get_free_pages+0x11/0x40
[ 9101.347880] ? tfw_pool_alloc_pages+0x47/0x50 [tempesta_fw]
[ 9101.347884] ? __tfw_pool_new+0x2d/0x70 [tempesta_fw]
[ 9101.347889] tfw_http_msg_process_generic+0x197/0x670 [tempesta_fw]
[ 9101.347893] ? ss_skb_chop_head_tail+0xbb/0x1d0 [tempesta_fw]
[ 9101.347898] ? ss_skb_process+0xf6/0x140 [tempesta_fw]
[ 9101.347902] tfw_h2_frame_process+0x308/0x440 [tempesta_fw]
[ 9101.347906] tfw_http_msg_process+0x42/0x50 [tempesta_fw]
[ 9101.347911] tfw_connection_recv+0x59/0xa0 [tempesta_fw]
[ 9101.347914] tfw_tls_connection_recv+0x19d/0x380 [tempesta_fw]
[ 9101.347919] ss_tcp_process_data+0x1e7/0x3f0 [tempesta_fw]
[ 9101.347924] ss_tcp_data_ready+0x44/0xb0 [tempesta_fw]
[ 9101.347925] tcp_data_ready+0x2b/0xd0
[ 9101.347926] tcp_rcv_established+0x5a7/0x670
[ 9101.347927] tcp_v4_do_rcv+0x140/0x200
[ 9101.347928] tcp_v4_rcv+0xcfd/0xe10
[ 9101.347929] ip_protocol_deliver_rcu+0x30/0x1b0
[ 9101.347930] ip_local_deliver_finish+0x48/0x60
[ 9101.347931] ip_local_deliver+0x72/0x110
[ 9101.347936] ? tfw_ipv4_nf_hook+0xb9/0x130 [tempesta_fw]
[ 9101.347937] ip_rcv_finish+0x87/0xa0
[ 9101.347938] ip_rcv+0xcc/0xe0
[ 9101.347938] ? ip_rcv_finish_core.isra.0+0x420/0x420
[ 9101.347940] __netif_receive_skb_one_core+0x88/0xa0
[ 9101.347941] __netif_receive_skb+0x18/0x60
[ 9101.347941] process_backlog+0xa9/0x160
[ 9101.347942] net_rx_action+0x13e/0x390
[ 9101.347944] __do_softirq+0xd9/0x291
[ 9101.347945] asm_call_irq_on_stack+0xf/0x20
[ 9101.347946] </IRQ>
[ 9101.347946] do_softirq_own_stack+0x3d/0x50
[ 9101.347947] do_softirq.part.0+0x46/0x50
[ 9101.347948] __local_bh_enable_ip+0x50/0x60
[ 9101.347949] ip_finish_output2+0x1ab/0x590
[ 9101.347950] ? __cgroup_bpf_run_filter_skb+0x3c3/0x3d0
[ 9101.347951] __ip_finish_output+0xd8/0x220
[ 9101.347952] ip_finish_output+0x2d/0xb0
[ 9101.347953] ip_output+0x7a/0x100
[ 9101.347954] ? ip_finish_output+0x2d/0xb0
[ 9101.347955] ip_local_out+0x3d/0x50
[ 9101.347956] __ip_queue_xmit+0x17a/0x470
[ 9101.347957] ? get_page_from_freelist+0xed8/0x1100
[ 9101.347958] ip_queue_xmit+0x15/0x20
[ 9101.347959] __tcp_transmit_skb+0xa94/0xc90
[ 9101.347960] tcp_write_xmit+0x453/0x1350
[ 9101.347961] __tcp_push_pending_frames+0x37/0x100
[ 9101.347962] tcp_push+0xfc/0x100
[ 9101.347964] tcp_sendmsg_locked+0xd36/0xe70
[ 9101.347965] tcp_sendmsg+0x2d/0x50
[ 9101.347966] inet_sendmsg+0x43/0x70
[ 9101.347967] sock_sendmsg+0x5e/0x70
[ 9101.347968] sock_write_iter+0x93/0xf0
[ 9101.347969] new_sync_write+0x192/0x1b0
[ 9101.347970] vfs_write+0x1ca/0x280
[ 9101.347971] ksys_write+0xb1/0xe0
[ 9101.347972] __x64_sys_write+0x1a/0x20
[ 9101.347973] do_syscall_64+0x38/0x90
[ 9101.347974] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 9101.347975] RIP: 0033:0x7f51322e62f7
[ 9101.347975] Code: 75 05 48 83 c4 58 c3 e8 f7 33 ff ff 0f 1f 80 00 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24
[ 9101.347976] RSP: 002b:00007ffddf5db4d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 9101.347977] RAX: ffffffffffffffda RBX: 0000000000000036 RCX: 00007f51322e62f7
[ 9101.347977] RDX: 0000000000000036 RSI: 0000558559fa1da3 RDI: 0000000000000005
[ 9101.347978] RBP: 0000558559f60ad0 R08: 0000000000000001 R09: 0000000000000008
[ 9101.347978] R10: 0000558559fa1da5 R11: 0000000000000246 R12: 0000558559fa1da3
[ 9101.347979] R13: 0000000000000036 R14: 0000558559f5ee20 R15: 0000000000000000
[ 9101.347980] ---[ end trace 50b1b7ebb7b42b30 ]---
Testing
Test to reproduce: long_body.test_long_request.H2PutRequestTest1k
All the warnings appear in https://github.com/tempesta-tech/tempesta/issues/1387
Fix is ready and would be merged as part of #1705 .