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.

Sign up for GitHub

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

Jump to bottom

http2: Fix various warnings #1705

Merged
merged 11 commits into from
Nov 8, 2022
Merged

http2: Fix various warnings #1705

merged 11 commits into from
Nov 8, 2022

Conversation

s0nx
Copy link
Contributor

@s0nx s0nx commented Sep 28, 2022

No description provided.

@s0nx s0nx self-assigned this Sep 28, 2022
@s0nx s0nx linked an issue Sep 28, 2022 that may be closed by this pull request
Warnings during h2 message exchanges #1387
Closed
5 tasks
@s0nx s0nx mentioned this pull request Oct 16, 2022
Closed
@s0nx s0nx marked this pull request as ready for review October 17, 2022 13:13
@s0nx s0nx force-pushed the pv-1387-h2-warn branch 2 times, most recently from 789d908 to 50e7870 Compare October 17, 2022 18:56
@const-t
Copy link
Contributor

const-t commented Oct 20, 2022

It's not a subject of current PR. However, during review I noticed few things.

  1. Legacy code from h1 version in __h2_parse_http_date
  2. We allow splitted cookie header for http2, but we MUST not send it to http1 server. See RFC 9113 8.2.3 and RFC 6265 5.4.

If there are multiple Cookie header fields after decompression, these MUST be concatenated into a single octet string using the two-octet delimiter of 0x3b, 0x20 (the ASCII string "; ")

  1. For full indexed header we calling tfw_hpack_hdr_set where coping already parsed value to currently parsing header, therefore parsing functions will not be called and parser state for current request will not be properly initialized. We handle such cases now for Host and If-Modified-Since, but not for other headers. Also handling it in such way not looks correctly, because of calling parsing functions directly from hpack. It's not a problem for one request, but it is a problem for multiplexed requests, because single hpack context used for whole connection and all requests/responses in it. For instance if we two such have requests in single connection:
':authority', 'localhost:81'
':path', '/'
':scheme', 'https'
':method', 'GET'

for first request TfwHttpReq.req_host_port will be 81, for second it will be 0. This applies to any other header during parsing which we change state of parser or request.

const-t
const-t approved these changes Oct 20, 2022
View reviewed changes
Copy link
Contributor

@const-t const-t left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've approved this PR, but with some comments about approach used in hpack, that might lead to errors.

fw/hpack.c Outdated Show resolved Hide resolved
fw/http_msg.c Outdated Show resolved Hide resolved
@s0nx
Copy link
Contributor Author

s0nx commented Oct 21, 2022

@RomanBelozerov
Copy link
Contributor

RomanBelozerov commented Oct 27, 2022 •
edited
Loading

Tempesta master crashes for h2 request with 500 MB+ body. Test.

dmesg 
[  283.670967] ------------[ cut here ]------------
[  283.671949] WARNING: CPU: 5 PID: 3051 at mm/page_alloc.c:4935 __alloc_pages_nodemask+0x268/0x300
[  283.673730] Modules linked in: tempesta_fw(OE) tempesta_db(OE) tempesta_tls(OE) tempesta_lib(OE) sha256_ssse3 sha512_ssse3 rfcomm bnep vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport vsock nls_iso8859_1 binfmt_misc intel_rapl_msr intel_rapl_common crct10dif_pclmul ghash_clmulni_intel aesni_intel snd_ens1371 crypto_simd snd_ac97_codec cryptd gameport glue_helper ac97_bus snd_pcm btusb btrtl snd_seq_midi snd_seq_midi_event btbcm btintel snd_rawmidi bluetooth snd_seq vmw_balloon snd_seq_device joydev snd_timer input_leds serio_raw snd ecdh_generic ecc soundcore vmw_vmci 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 ramoops pstore_blk reed_solomon efi_pstore pstore_zone ip_tables x_tables autofs4 hid_generic usbhid hid mptspi psmouse crc32_pclmul e1000 mptscsih ahci mptbase i2c_piix4 libahci scsi_transport_spi pata_acpi
[  283.673786]  [last unloaded: tempesta_lib]
[  283.691803] CPU: 5 PID: 3051 Comm: curl Kdump: loaded Tainted: G           OE     5.10.35+ #1
[  283.693529] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
[  283.695779] RIP: 0010:__alloc_pages_nodemask+0x268/0x300
[  283.696892] Code: 08 44 89 f9 44 89 ea 4c 89 f6 e8 23 95 fc ff e9 4c ff ff ff e8 c9 15 fc ff 48 89 c7 e9 b8 fe ff ff 41 81 e4 00 20 00 00 75 a7 <0f> 0b eb a3 31 c0 e9 4a fe ff ff 65 48 8b 04 25 c0 7b 01 00 8b 40
[  283.700779] RSP: 0018:ffffb856405b0758 EFLAGS: 00010246
[  283.701876] RAX: 0000000000000000 RBX: 0000000000000001 RCX: 0000000000000000
[  283.703435] RDX: 0000000000000000 RSI: 000000000000000b RDI: 0000000000000a20
[  283.704900] RBP: ffffb856405b07b0 R08: 0000000000000001 R09: 0000000000400010
[  283.706438] R10: ffff8d76662a20f0 R11: 0000000000000009 R12: 0000000000000000
[  283.707860] R13: ffffffff8c9d1c40 R14: 000000000000000b R15: 0000000000000000
[  283.709308] FS:  00007f0ba9486b80(0000) GS:ffff8d7775f40000(0000) knlGS:0000000000000000
[  283.711057] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  283.712236] CR2: 00007f0ba9a2a520 CR3: 000000000115a006 CR4: 0000000000370ee0
[  283.713665] Call Trace:
[  283.714294]  <IRQ>
[  283.714746]  alloc_pages_current+0x87/0xe0
[  283.715584]  __get_free_pages+0x11/0x40
[  283.716390]  tfw_pool_alloc_pages+0x47/0x50 [tempesta_fw]
[  283.717825]  __tfw_pool_alloc_page+0x3d/0x90 [tempesta_fw]
[  283.719387]  __tfw_pool_realloc+0xd4/0xe0 [tempesta_fw]
[  283.721090]  __str_grow_tree+0x4a/0x140 [tempesta_fw]
[  283.722279]  tfw_str_add_compound+0x1b/0x20 [tempesta_fw]
[  283.723441]  __tfw_http_msg_add_str_data+0x3d/0xe0 [tempesta_fw]
[  283.724747]  tfw_h2_parse_req+0xf0/0x1c0 [tempesta_fw]
[  283.725852]  ss_skb_process+0xf6/0x140 [tempesta_fw]
[  283.727057]  ? tfw_http_parse_req+0xe1a0/0xe1a0 [tempesta_fw]
[  283.728319]  ? tfw_http_parse_req+0xe1a0/0xe1a0 [tempesta_fw]
[  283.729552]  tfw_http_req_process+0x7f/0x960 [tempesta_fw]
[  283.730854]  ? tfw_h2_frame_recv+0x243/0x1f80 [tempesta_fw]
[  283.732065]  tfw_http_msg_process_generic+0x197/0x670 [tempesta_fw]
[  283.733409]  ? ss_skb_process+0xf6/0x140 [tempesta_fw]
[  283.734639]  ? tfw_h2_conn_terminate_close+0x40/0x40 [tempesta_fw]
[  283.735990]  tfw_h2_frame_process+0x308/0x440 [tempesta_fw]
[  283.737193]  tfw_http_msg_process+0x42/0x50 [tempesta_fw]
[  283.738468]  tfw_connection_recv+0x59/0xa0 [tempesta_fw]
[  283.739659]  tfw_tls_connection_recv+0x19d/0x380 [tempesta_fw]
[  283.740918]  ss_tcp_process_data+0x1e7/0x3f0 [tempesta_fw]
[  283.742090]  ss_tcp_data_ready+0x44/0xb0 [tempesta_fw]
[  283.743438]  tcp_data_ready+0x2b/0xd0
[  283.744452]  tcp_rcv_established+0x5a7/0x670
[  283.745453]  ? sk_filter_trim_cap+0xde/0x240
[  283.746536]  tcp_v4_do_rcv+0x140/0x200
[  283.747401]  tcp_v4_rcv+0xcfd/0xe10
[  283.748176]  ip_protocol_deliver_rcu+0x30/0x1b0
[  283.749187]  ip_local_deliver_finish+0x48/0x60
[  283.750165]  ip_local_deliver+0x72/0x110
[  283.751152]  ? tfw_ipv4_nf_hook+0xb9/0x130 [tempesta_fw]
[  283.752340]  ip_rcv_finish+0x87/0xa0
[  283.753125]  ip_rcv+0xcc/0xe0
[  283.753909]  ? ip_rcv_finish_core.isra.0+0x420/0x420
[  283.755009]  __netif_receive_skb_one_core+0x88/0xa0
[  283.756081]  __netif_receive_skb+0x18/0x60
[  283.756985]  process_backlog+0xa9/0x160
[  283.757946]  net_rx_action+0x13e/0x390
[  283.758621]  ? rcu_core+0xfa/0x500
[  283.759239]  __do_softirq+0xd9/0x291
[  283.759870]  asm_call_irq_on_stack+0x12/0x20
[  283.760800]  </IRQ>
[  283.761270]  do_softirq_own_stack+0x3d/0x50
[  283.762313]  do_softirq.part.0+0x46/0x50
[  283.763169]  __local_bh_enable_ip+0x50/0x60
[  283.764111]  ip_finish_output2+0x1ab/0x590
[  283.764947]  ? __cgroup_bpf_run_filter_skb+0x3c3/0x3d0
[  283.766019]  __ip_finish_output+0xd8/0x220
[  283.766734]  ? __wake_up_common+0x7e/0x140
[  283.767666]  ip_finish_output+0x2d/0xb0
[  283.768501]  ip_output+0x7a/0x100
[  283.769457]  ? set_pageblock_migratetype+0x39/0x40
[  283.771861]  ip_local_out+0x3d/0x50
[  283.773168]  __ip_queue_xmit+0x17a/0x470
[  283.774533]  ? get_page_from_freelist+0xed8/0x1100
[  283.776049]  ip_queue_xmit+0x15/0x20
[  283.776893]  __tcp_transmit_skb+0xa94/0xc90
[  283.778065]  tcp_write_xmit+0x453/0x1350
[  283.779036]  __tcp_push_pending_frames+0x37/0x100
[  283.780130]  tcp_push+0xfc/0x100
[  283.780839]  tcp_sendmsg_locked+0xd36/0xe70
[  283.781795]  tcp_sendmsg+0x2d/0x50
[  283.782430]  inet_sendmsg+0x43/0x70
[  283.783174]  sock_sendmsg+0x5e/0x70
[  283.783935]  sock_write_iter+0x93/0xf0
[  283.784759]  new_sync_write+0x192/0x1b0
[  283.785732]  vfs_write+0x1ca/0x280
[  283.786514]  ksys_write+0xb1/0xe0
[  283.787245]  __x64_sys_write+0x1a/0x20
[  283.788066]  do_syscall_64+0x38/0x90
[  283.788844]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[  283.790076] RIP: 0033:0x7f0ba9a272f7
[  283.790974] 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
[  283.795149] RSP: 002b:00007fff282ba368 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  283.796847] RAX: ffffffffffffffda RBX: 0000000000000026 RCX: 00007f0ba9a272f7
[  283.798508] RDX: 0000000000000026 RSI: 000055d9f9228c83 RDI: 0000000000000006
[  283.800067] RBP: 000055d9f92009c0 R08: 0000000000000001 R09: 0000000000000008
[  283.801688] R10: 000055d9f9228c85 R11: 0000000000000246 R12: 000055d9f9228c83
[  283.803244] R13: 0000000000000026 R14: 000055d9f91fed10 R15: 0000000000000000
[  283.804781] ---[ end trace 9dcd1d8884faa490 ]---
[  283.805907] [tempesta fw] Warning: Cannot grow HTTP data string
[  283.807127] [tempesta fw] Warning: failed to parse request: 127.0.0.1
[  283.808552] ------------[ cut here ]------------
[  283.809602] WARNING: CPU: 5 PID: 3051 at /root/tempesta/fw/http_stream.c:89 tfw_h2_stream_fsm+0x12d/0x2b0 [tempesta_fw]
[  283.811886] Modules linked in: tempesta_fw(OE) tempesta_db(OE) tempesta_tls(OE) tempesta_lib(OE) sha256_ssse3 sha512_ssse3 rfcomm bnep vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport vsock nls_iso8859_1 binfmt_misc intel_rapl_msr intel_rapl_common crct10dif_pclmul ghash_clmulni_intel aesni_intel snd_ens1371 crypto_simd snd_ac97_codec cryptd gameport glue_helper ac97_bus snd_pcm btusb btrtl snd_seq_midi snd_seq_midi_event btbcm btintel snd_rawmidi bluetooth snd_seq vmw_balloon snd_seq_device joydev snd_timer input_leds serio_raw snd ecdh_generic ecc soundcore vmw_vmci 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 ramoops pstore_blk reed_solomon efi_pstore pstore_zone ip_tables x_tables autofs4 hid_generic usbhid hid mptspi psmouse crc32_pclmul e1000 mptscsih ahci mptbase i2c_piix4 libahci scsi_transport_spi pata_acpi
[  283.811940]  [last unloaded: tempesta_lib]
[  283.828912] CPU: 5 PID: 3051 Comm: curl Kdump: loaded Tainted: G        W  OE     5.10.35+ #1
[  283.830414] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
[  283.832161] RIP: 0010:tfw_h2_stream_fsm+0x12d/0x2b0 [tempesta_fw]
[  283.833149] 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
[  283.836301] RSP: 0018:ffffb856405b0530 EFLAGS: 00010293
[  283.837153] RAX: 0000000000000002 RBX: ffff8d76e04b82c0 RCX: 0000000000000001
[  283.838317] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff8d76e04b82f0
[  283.839674] RBP: ffffb856405b0560 R08: ffffb856405b057c R09: 0000000000000000
[  283.840858] R10: 00000000ffffffff R11: a3d70a3d70a3d70b R12: ffff8d76e04b82f0
[  283.842062] R13: 0000000000000001 R14: 0000000000000001 R15: 0000000000000001
[  283.843418] FS:  00007f0ba9486b80(0000) GS:ffff8d7775f40000(0000) knlGS:0000000000000000
[  283.844765] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  283.845757] CR2: 00007f0ba9a2a520 CR3: 000000000115a006 CR4: 0000000000370ee0
[  283.847385] Call Trace:
[  283.847916]  <IRQ>
[  283.848370]  tfw_h2_stream_id_close+0xe7/0x110 [tempesta_fw]
[  283.849429]  tfw_h2_prep_resp+0x95/0x310 [tempesta_fw]
[  283.850305]  ? alloc_pages_current+0x87/0xe0
[  283.851187]  tfw_h2_send_resp+0x5c/0xb0 [tempesta_fw]
[  283.852045]  tfw_h2_send_err_resp+0x9a/0xc0 [tempesta_fw]
[  283.852926]  tfw_http_cli_error_resp_and_log+0x3cd/0x440 [tempesta_fw]
[  283.854200]  ? tfw_http_parse_req+0xe1a0/0xe1a0 [tempesta_fw]
[  283.855181]  tfw_http_req_process+0xf6/0x960 [tempesta_fw]
[  283.856064]  ? tfw_h2_frame_recv+0x243/0x1f80 [tempesta_fw]
[  283.856963]  tfw_http_msg_process_generic+0x197/0x670 [tempesta_fw]
[  283.857998]  ? ss_skb_process+0xf6/0x140 [tempesta_fw]
[  283.858920]  ? tfw_h2_conn_terminate_close+0x40/0x40 [tempesta_fw]
[  283.860019]  tfw_h2_frame_process+0x308/0x440 [tempesta_fw]
[  283.860916]  tfw_http_msg_process+0x42/0x50 [tempesta_fw]
[  283.861806]  tfw_connection_recv+0x59/0xa0 [tempesta_fw]
[  283.862787]  tfw_tls_connection_recv+0x19d/0x380 [tempesta_fw]
[  283.863808]  ss_tcp_process_data+0x1e7/0x3f0 [tempesta_fw]
[  283.864697]  ss_tcp_data_ready+0x44/0xb0 [tempesta_fw]
[  283.865730]  tcp_data_ready+0x2b/0xd0
[  283.866423]  tcp_rcv_established+0x5a7/0x670
[  283.867112]  ? sk_filter_trim_cap+0xde/0x240
[  283.867802]  tcp_v4_do_rcv+0x140/0x200
[  283.868416]  tcp_v4_rcv+0xcfd/0xe10
[  283.868984]  ip_protocol_deliver_rcu+0x30/0x1b0
[  283.869740]  ip_local_deliver_finish+0x48/0x60
[  283.870586]  ip_local_deliver+0x72/0x110
[  283.871268]  ? tfw_ipv4_nf_hook+0xb9/0x130 [tempesta_fw]
[  283.872150]  ip_rcv_finish+0x87/0xa0
[  283.872744]  ip_rcv+0xcc/0xe0
[  283.873248]  ? ip_rcv_finish_core.isra.0+0x420/0x420
[  283.874229]  __netif_receive_skb_one_core+0x88/0xa0
[  283.875037]  __netif_receive_skb+0x18/0x60
[  283.875723]  process_backlog+0xa9/0x160
[  283.876395]  net_rx_action+0x13e/0x390
[  283.877056]  ? rcu_core+0xfa/0x500
[  283.877751]  __do_softirq+0xd9/0x291
[  283.878352]  asm_call_irq_on_stack+0x12/0x20
[  283.879041]  </IRQ>
[  283.879391]  do_softirq_own_stack+0x3d/0x50
[  283.880064]  do_softirq.part.0+0x46/0x50
[  283.880704]  __local_bh_enable_ip+0x50/0x60
[  283.881385]  ip_finish_output2+0x1ab/0x590
[  283.882183]  ? __cgroup_bpf_run_filter_skb+0x3c3/0x3d0
[  283.883126]  __ip_finish_output+0xd8/0x220
[  283.883794]  ? __wake_up_common+0x7e/0x140
[  283.884458]  ip_finish_output+0x2d/0xb0
[  283.885080]  ip_output+0x7a/0x100
[  283.885620]  ? set_pageblock_migratetype+0x39/0x40
[  283.886566]  ip_local_out+0x3d/0x50
[  283.887167]  __ip_queue_xmit+0x17a/0x470
[  283.887837]  ? get_page_from_freelist+0xed8/0x1100
[  283.888668]  ip_queue_xmit+0x15/0x20
[  283.889278]  __tcp_transmit_skb+0xa94/0xc90
[  283.890124]  tcp_write_xmit+0x453/0x1350
[  283.890787]  __tcp_push_pending_frames+0x37/0x100
[  283.891543]  tcp_push+0xfc/0x100
[  283.892068]  tcp_sendmsg_locked+0xd36/0xe70
[  283.892777]  tcp_sendmsg+0x2d/0x50
[  283.893334]  inet_sendmsg+0x43/0x70
[  283.894049]  sock_sendmsg+0x5e/0x70
[  283.894637]  sock_write_iter+0x93/0xf0
[  283.895244]  new_sync_write+0x192/0x1b0
[  283.895869]  vfs_write+0x1ca/0x280
[  283.896423]  ksys_write+0xb1/0xe0
[  283.896961]  __x64_sys_write+0x1a/0x20
[  283.897744]  do_syscall_64+0x38/0x90
[  283.898454]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[  283.899323] RIP: 0033:0x7f0ba9a272f7
[  283.899909] 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
[  283.903020] RSP: 002b:00007fff282ba368 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  283.904303] RAX: ffffffffffffffda RBX: 0000000000000026 RCX: 00007f0ba9a272f7
[  283.905483] RDX: 0000000000000026 RSI: 000055d9f9228c83 RDI: 0000000000000006
[  283.907016] RBP: 000055d9f92009c0 R08: 0000000000000001 R09: 0000000000000008
[  283.908470] R10: 000055d9f9228c85 R11: 0000000000000246 R12: 000055d9f9228c83
[  283.910047] R13: 0000000000000026 R14: 000055d9f91fed10 R15: 0000000000000000
[  283.911324] ---[ end trace 9dcd1d8884faa491 ]---

This PR fixed crash, but I do not receive response to h2 request with 1 GB body and receive:

[tempesta fw] Warning: Cannot grow HTTP data string

or

dmesg 
[19591.619070] Start test: t_long_body.test_long_request.ChunkedLongBodyInRequest.test_h2
[19594.690481] [tdb] Start Tempesta DB
[19594.712216] [tempesta fw] Initializing Tempesta FW kernel module...
[19594.757281] [tempesta fw] Configuration processing is completed.
[19594.777785] [tdb] Opened table /opt/tempesta/db/filter0.tdb: size=16777216 rec_size=20 base=000000002396439e
[19594.785685] [tdb] Opened table /opt/tempesta/db/sessions0.tdb: size=16777216 rec_size=312 base=000000004bd8fa47
[19594.792612] [tdb] Opened table /opt/tempesta/db/client0.tdb: size=16777216 rec_size=624 base=0000000015ae5ff4
[19594.821552] [tempesta fw] Open listen socket on: 0.0.0.0:4433
[19594.825422] [tempesta fw] Open listen socket on: 0.0.0.0:443
[19594.828591] [tempesta fw] Open listen socket on: 0.0.0.0
[19594.865619] [tempesta fw] Tempesta FW is ready
[19597.903581] curl: page allocation failure: order:10, mode:0xa20(GFP_ATOMIC), nodemask=(null),cpuset=/,mems_allowed=0
[19597.905419] CPU: 3 PID: 46018 Comm: curl Kdump: loaded Tainted: G        W  OE     5.10.35+ #1
[19597.907250] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
[19597.909261] Call Trace:
[19597.909685]  <IRQ>
[19597.910117]  dump_stack+0x74/0x92
[19597.910760]  warn_alloc.cold+0x7b/0xdf
[19597.911552]  __alloc_pages_slowpath.constprop.0+0xcf8/0xd10
[19597.912538]  __alloc_pages_nodemask+0x2a0/0x300
[19597.913422]  alloc_pages_current+0x87/0xe0
[19597.914228]  __get_free_pages+0x11/0x40
[19597.914947]  tfw_pool_alloc_pages+0x47/0x50 [tempesta_fw]
[19597.915960]  __tfw_pool_alloc_page+0x3d/0x90 [tempesta_fw]
[19597.917070]  __tfw_pool_realloc+0xd4/0xe0 [tempesta_fw]
[19597.918202]  __str_grow_tree+0x4a/0x140 [tempesta_fw]
[19597.919266]  tfw_str_add_compound+0x1b/0x20 [tempesta_fw]
[19597.920526]  __tfw_http_msg_add_str_data+0x3d/0xe0 [tempesta_fw]
[19597.921835]  tfw_h2_parse_req+0x196/0x210 [tempesta_fw]
[19597.922979]  ss_skb_process+0xf6/0x140 [tempesta_fw]
[19597.924078]  ? tfw_http_parse_req+0xe190/0xe190 [tempesta_fw]
[19597.925417]  ? tfw_http_parse_req+0xe190/0xe190 [tempesta_fw]
[19597.926734]  tfw_http_req_process+0x7f/0x960 [tempesta_fw]
[19597.927946]  ? generic_gcmaes_decrypt+0x5a/0x70 [aesni_intel]
[19597.929156]  ? memcpy_fast+0xe/0x10 [tempesta_lib]
[19597.930275]  ? tfw_h2_frame_recv+0x1387/0x1f80 [tempesta_fw]
[19597.931482]  tfw_http_msg_process_generic+0x197/0x670 [tempesta_fw]
[19597.932755]  ? ss_skb_chop_head_tail+0xbb/0x1d0 [tempesta_fw]
[19597.934065]  ? ss_skb_process+0xf6/0x140 [tempesta_fw]
[19597.935190]  tfw_h2_frame_process+0x23d/0x440 [tempesta_fw]
[19597.936441]  tfw_http_msg_process+0x42/0x50 [tempesta_fw]
[19597.937656]  tfw_connection_recv+0x59/0xa0 [tempesta_fw]
[19597.938826]  tfw_tls_connection_recv+0x19d/0x380 [tempesta_fw]
[19597.940145]  ss_tcp_process_data+0x1e7/0x3f0 [tempesta_fw]
[19597.941440]  ss_tcp_data_ready+0x44/0xb0 [tempesta_fw]
[19597.942572]  tcp_data_ready+0x2b/0xd0
[19597.943365]  tcp_rcv_established+0x5a7/0x670
[19597.944264]  tcp_v4_do_rcv+0x140/0x200
[19597.945128]  tcp_v4_rcv+0xcfd/0xe10
[19597.945849]  ip_protocol_deliver_rcu+0x30/0x1b0
[19597.946895]  ip_local_deliver_finish+0x48/0x60
[19597.947928]  ip_local_deliver+0x72/0x110
[19597.948792]  ? tfw_ipv4_nf_hook+0xb9/0x130 [tempesta_fw]
[19597.950006]  ip_rcv_finish+0x87/0xa0
[19597.950836]  ip_rcv+0xcc/0xe0
[19597.951641]  ? ip_rcv_finish_core.isra.0+0x420/0x420
[19597.952772]  __netif_receive_skb_one_core+0x88/0xa0
[19597.953744]  __netif_receive_skb+0x18/0x60
[19597.954551]  process_backlog+0xa9/0x160
[19597.955336]  net_rx_action+0x13e/0x390
[19597.956000]  ? clockevents_program_event+0x8f/0xe0
[19597.956878]  __do_softirq+0xd9/0x291
[19597.957640]  asm_call_irq_on_stack+0x12/0x20
[19597.958376]  </IRQ>
[19597.958860]  do_softirq_own_stack+0x3d/0x50
[19597.959657]  do_softirq.part.0+0x46/0x50
[19597.960332]  __local_bh_enable_ip+0x50/0x60
[19597.961179]  ip_finish_output2+0x1ab/0x590
[19597.962055]  ? __cgroup_bpf_run_filter_skb+0x3c3/0x3d0
[19597.963079]  __ip_finish_output+0xd8/0x220
[19597.964068]  ip_finish_output+0x2d/0xb0
[19597.964881]  ip_output+0x7a/0x100
[19597.965615]  ip_local_out+0x3d/0x50
[19597.966441]  __ip_queue_xmit+0x17a/0x470
[19597.967245]  ? prep_new_page+0xfb/0x120
[19597.967993]  ip_queue_xmit+0x15/0x20
[19597.968688]  __tcp_transmit_skb+0xa94/0xc90
[19597.969492]  tcp_write_xmit+0x453/0x1350
[19597.970318]  __tcp_push_pending_frames+0x37/0x100
[19597.971135]  tcp_push+0xfc/0x100
[19597.971856]  tcp_sendmsg_locked+0xd36/0xe70
[19597.972618]  tcp_sendmsg+0x2d/0x50
[19597.973362]  inet_sendmsg+0x43/0x70
[19597.973981]  sock_sendmsg+0x5e/0x70
[19597.974612]  sock_write_iter+0x93/0xf0
[19597.975368]  new_sync_write+0x192/0x1b0
[19597.976148]  vfs_write+0x1ca/0x280
[19597.976797]  ksys_write+0xb1/0xe0
[19597.977484]  __x64_sys_write+0x1a/0x20
[19597.978149]  do_syscall_64+0x38/0x90
[19597.978780]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[19597.979756] RIP: 0033:0x7f8ba68da2f7
[19597.980407] 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
[19597.984146] RSP: 002b:00007ffed7acdbc8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[19597.985625] RAX: ffffffffffffffda RBX: 000000000000401d RCX: 00007f8ba68da2f7
[19597.986978] RDX: 000000000000401d RSI: 000055c4684b4c83 RDI: 0000000000000006
[19597.988312] RBP: 000055c46848c9c0 R08: 0000000000000001 R09: 0000000000000008
[19597.989574] R10: 000055c4684b4c85 R11: 0000000000000246 R12: 000055c4684b4c83
[19597.990902] R13: 000000000000401d R14: 000055c46848ad10 R15: 0000000000000000
[19597.992440] Mem-Info:
[19597.992913] active_anon:12549 inactive_anon:1138106 isolated_anon:0
[19597.992913]  active_file:84630 inactive_file:91736 isolated_file:0
[19597.992913]  unevictable:0 dirty:46 writeback:0
[19597.992913]  slab_reclaimable:21888 slab_unreclaimable:25182
[19597.992913]  mapped:53040 shmem:5129 pagetables:8029 bounce:0
[19597.992913]  free:224524 free_pcp:1289 free_cma:0
[19597.999082] Node 0 active_anon:50196kB inactive_anon:4552424kB active_file:338692kB inactive_file:366944kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:212332kB dirty:184kB writeback:0kB shmem:20516kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB kernel_stack:17424kB all_unreclaimable? no
[19598.004483] Node 0 DMA free:14304kB min:144kB low:180kB high:216kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15988kB managed:15360kB mlocked:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[19598.009801] lowmem_reserve[]: 0 2028 6975 6975 6975
[19598.010884] Node 0 DMA32 free:407436kB min:19612kB low:24512kB high:29412kB reserved_highatomic:2048KB active_anon:1856kB inactive_anon:1762072kB active_file:37268kB inactive_file:279756kB unevictable:0kB writepending:0kB present:3129152kB managed:2834912kB mlocked:0kB pagetables:6372kB bounce:0kB free_pcp:1328kB local_pcp:0kB free_cma:0kB
[19598.017756] lowmem_reserve[]: 0 0 4946 4946 4946
[19598.018823] Node 0 Normal free:474844kB min:47824kB low:59780kB high:71736kB reserved_highatomic:2048KB active_anon:48144kB inactive_anon:2790480kB active_file:302268kB inactive_file:86720kB unevictable:0kB writepending:12kB present:5242880kB managed:5065572kB mlocked:0kB pagetables:25744kB bounce:0kB free_pcp:3740kB local_pcp:1468kB free_cma:0kB
[19598.026069] lowmem_reserve[]: 0 0 0 0 0
[19598.026906] Node 0 DMA: 0*4kB 0*8kB 0*16kB 1*32kB (U) 1*64kB (U) 1*128kB (U) 1*256kB (U) 1*512kB (U) 1*1024kB (U) 2*2048kB (UM) 2*4096kB (M) = 14304kB
[19598.030101] Node 0 DMA32: 4146*4kB (UME) 1698*8kB (UME) 1425*16kB (UME) 2887*32kB (ME) 1541*64kB (ME) 507*128kB (ME) 82*256kB (ME) 60*512kB (ME) 46*1024kB (ME) 0*2048kB 0*4096kB = 407688kB
[19598.033980] Node 0 Normal: 27042*4kB (UMEH) 26998*8kB (UMEH) 8468*16kB (UMEH) 395*32kB (UMH) 2*64kB (EH) 2*128kB (H) 1*256kB (H) 2*512kB (H) 0*1024kB 0*2048kB 0*4096kB = 473944kB
[19598.037878] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
[19598.039834] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[19598.041992] 187772 total pagecache pages
[19598.042924] 5866 pages in swap cache
[19598.043683] Swap cache stats: add 119069, delete 113202, find 9496/22408
[19598.045368] Free swap  = 1967408kB
[19598.046152] Total swap = 2097148kB
[19598.047016] 2097005 pages RAM
[19598.047703] 0 pages HighMem/MovableOnly
[19598.048772] 118044 pages reserved
[19598.049586] 0 pages hwpoisoned
[19598.050308] [tempesta fw] Warning: Cannot grow HTTP data string
[19598.051775] [tempesta fw] failed to parse request: 127.0.0.1
[19598.495662] [tdb] Close table 'client0.tdb'
[19598.506425] [tdb] Close table 'sessions0.tdb'
[19598.558068] [tdb] Close table 'filter0.tdb'
[19598.558969] [tempesta fw] modules are stopped
[19598.592709] [tempesta fw] exiting...
[19598.673040] [tdb] Shutdown Tempesta DB
[19600.679386] End test:   t_long_body.test_long_request.ChunkedLongBodyInRequest.test_h2

or

dmesg 
[  213.876952] WARNING: CPU: 5 PID: 3153 at mm/page_alloc.c:4935 __alloc_pages_nodemask+0x268/0x300
[  213.883545] Modules linked in: tempesta_fw(OE) tempesta_db(OE) sha256_ssse3 sha512_ssse3 tempesta_tls(OE) tempesta_lib(OE) rfcomm bnep vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport vsock nls_iso8859_1 binfmt_misc intel_rapl_msr intel_rapl_common crct10dif_pclmul ghash_clmulni_intel aesni_intel btusb snd_ens1371 btrtl crypto_simd snd_ac97_codec cryptd btbcm gameport btintel glue_helper ac97_bus bluetooth snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device snd_timer vmw_balloon snd ecdh_generic input_leds ecc joydev serio_raw vmw_vmci soundcore sch_fq_codel mac_hid vmwgfx 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 pstore_zone reed_solomon 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 pata_acpi
[  213.989768] CPU: 5 PID: 3153 Comm: curl Kdump: loaded Tainted: G           OE     5.10.35+ #1
[  213.991355] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 11/12/2020
[  213.993438] RIP: 0010:__alloc_pages_nodemask+0x268/0x300
[  213.994414] Code: 08 44 89 f9 44 89 ea 4c 89 f6 e8 23 95 fc ff e9 4c ff ff ff e8 c9 15 fc ff 48 89 c7 e9 b8 fe ff ff 41 81 e4 00 20 00 00 75 a7 <0f> 0b eb a3 31 c0 e9 4a fe ff ff 65 48 8b 04 25 c0 7b 01 00 8b 40
[  213.997910] RSP: 0018:ffffba67405b0758 EFLAGS: 00010246
[  213.998905] RAX: 0000000000000000 RBX: 0000000000000001 RCX: 0000000000000000
[  214.000222] RDX: 0000000000000000 RSI: 000000000000000b RDI: 0000000000000a20
[  214.001680] RBP: ffffba67405b07b0 R08: 0000000000000001 R09: 0000000000400010
[  214.003023] R10: ffff90fe1af5dc4c R11: 0000000000000009 R12: 0000000000000000
[  214.004358] R13: ffffffff891d1c40 R14: 000000000000000b R15: 0000000000000000
[  214.005677] FS:  00007f2cb4603b80(0000) GS:ffff90fe35f40000(0000) knlGS:0000000000000000
[  214.007270] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  214.008336] CR2: 0000563f18ea4000 CR3: 0000000032494003 CR4: 0000000000370ee0
[  214.009703] Call Trace:
[  214.010327]  <IRQ>
[  214.010763]  alloc_pages_current+0x87/0xe0
[  214.011550]  __get_free_pages+0x11/0x40
[  214.012404]  tfw_pool_alloc_pages+0x47/0x50 [tempesta_fw]
[  214.013438]  __tfw_pool_alloc_page+0x3d/0x90 [tempesta_fw]
[  214.014655]  __tfw_pool_realloc+0xd4/0xe0 [tempesta_fw]
[  214.015664]  __str_grow_tree+0x4a/0x140 [tempesta_fw]
[  214.016615]  tfw_str_add_compound+0x1b/0x20 [tempesta_fw]
[  214.017620]  __tfw_http_msg_add_str_data+0x3d/0xe0 [tempesta_fw]
[  214.018938]  tfw_h2_parse_req+0x141/0x210 [tempesta_fw]
[  214.019957]  ss_skb_process+0xf6/0x140 [tempesta_fw]
[  214.020918]  ? tfw_http_parse_req+0xe190/0xe190 [tempesta_fw]
[  214.022157]  ? tfw_http_parse_req+0xe190/0xe190 [tempesta_fw]
[  214.023285]  tfw_http_req_process+0x7f/0x960 [tempesta_fw]
[  214.024305]  ? tfw_h2_frame_recv+0x243/0x1f80 [tempesta_fw]
[  214.025352]  tfw_http_msg_process_generic+0x197/0x670 [tempesta_fw]
[  214.026682]  ? ss_skb_process+0xf6/0x140 [tempesta_fw]
[  214.027668]  ? tfw_h2_conn_terminate_close+0x40/0x40 [tempesta_fw]
[  214.028826]  tfw_h2_frame_process+0x23d/0x440 [tempesta_fw]
[  214.029987]  tfw_http_msg_process+0x42/0x50 [tempesta_fw]
[  214.031019]  tfw_connection_recv+0x59/0xa0 [tempesta_fw]
[  214.032039]  tfw_tls_connection_recv+0x19d/0x380 [tempesta_fw]
[  214.033139]  ss_tcp_process_data+0x1e7/0x3f0 [tempesta_fw]
[  214.034297]  ss_tcp_data_ready+0x44/0xb0 [tempesta_fw]
[  214.035255]  tcp_data_ready+0x2b/0xd0
[  214.035951]  tcp_rcv_established+0x5a7/0x670
[  214.036768]  ? sk_filter_trim_cap+0xde/0x240
[  214.037722]  tcp_v4_do_rcv+0x140/0x200
[  214.038472]  tcp_v4_rcv+0xcfd/0xe10
[  214.039167]  ip_protocol_deliver_rcu+0x30/0x1b0
[  214.040040]  ip_local_deliver_finish+0x48/0x60
[  214.040881]  ip_local_deliver+0x72/0x110
[  214.041785]  ? tfw_ipv4_nf_hook+0xb9/0x130 [tempesta_fw]
[  214.042796]  ip_rcv_finish+0x87/0xa0
[  214.043505]  ip_rcv+0xcc/0xe0
[  214.044093]  ? ip_rcv_finish_core.isra.0+0x420/0x420
[  214.045046]  __netif_receive_skb_one_core+0x88/0xa0
[  214.046079]  __netif_receive_skb+0x18/0x60
[  214.046821]  process_backlog+0xa9/0x160
[  214.047528]  net_rx_action+0x13e/0x390
[  214.048199]  ? clockevents_program_event+0x8f/0xe0
[  214.049076]  __do_softirq+0xd9/0x291
[  214.049747]  asm_call_irq_on_stack+0x12/0x20
[  214.050611]  </IRQ>
[  214.051039]  do_softirq_own_stack+0x3d/0x50
[  214.051775]  do_softirq.part.0+0x46/0x50
[  214.052662]  __local_bh_enable_ip+0x50/0x60
[  214.053647]  ip_finish_output2+0x1ab/0x590
[  214.054737]  ? __cgroup_bpf_run_filter_skb+0x3c3/0x3d0
[  214.055795]  __ip_finish_output+0xd8/0x220
[  214.056550]  ip_finish_output+0x2d/0xb0
[  214.057284]  ip_output+0x7a/0x100
[  214.058055]  ip_local_out+0x3d/0x50
[  214.058748]  __ip_queue_xmit+0x17a/0x470
[  214.059674]  ip_queue_xmit+0x15/0x20
[  214.060353]  __tcp_transmit_skb+0xa94/0xc90
[  214.061118]  tcp_write_xmit+0x453/0x1350
[  214.062046]  __tcp_push_pending_frames+0x37/0x100
[  214.062926]  tcp_push+0xfc/0x100
[  214.063564]  tcp_sendmsg_locked+0xd36/0xe70
[  214.064314]  tcp_sendmsg+0x2d/0x50
[  214.064950]  inet_sendmsg+0x43/0x70
[  214.065757]  sock_sendmsg+0x5e/0x70
[  214.066467]  sock_write_iter+0x93/0xf0
[  214.067186]  new_sync_write+0x192/0x1b0
[  214.067953]  vfs_write+0x1ca/0x280
[  214.068587]  ksys_write+0xb1/0xe0
[  214.069378]  __x64_sys_write+0x1a/0x20
[  214.070160]  do_syscall_64+0x38/0x90
[  214.070980]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[  214.072168] RIP: 0033:0x7f2cb4ba42f7
[  214.073297] 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
[  214.077630] RSP: 002b:00007ffe5ec89e48 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[  214.079335] RAX: ffffffffffffffda RBX: 0000000000000026 RCX: 00007f2cb4ba42f7
[  214.080966] RDX: 0000000000000026 RSI: 0000563f18ea1c83 RDI: 0000000000000006
[  214.082739] RBP: 0000563f18e799c0 R08: 0000000000000001 R09: 0000000000000008
[  214.084381] R10: 0000563f18ea1c85 R11: 0000000000000246 R12: 0000563f18ea1c83
[  214.085965] R13: 0000000000000026 R14: 0000563f18e77d10 R15: 0000000000000000
[  214.087235] ---[ end trace 785992a707380521 ]---
And also it fix comment https://github.com//issues/1703#issuecomment-1268475093, but I don't receive respone for h2 request with MTU 80.

krizhanovsky
krizhanovsky approved these changes Nov 7, 2022
View reviewed changes
Copy link
Contributor

@krizhanovsky krizhanovsky left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good to merge after several cleanups

fw/http.c Outdated Show resolved Hide resolved
fw/http.c Outdated Show resolved Hide resolved
fw/http_parser.c Show resolved Hide resolved
fw/http_parser.c Outdated Show resolved Hide resolved
fw/http_stream.c Show resolved Hide resolved
fw/http.c Outdated Show resolved Hide resolved
@RomanBelozerov RomanBelozerov mentioned this pull request Nov 8, 2022
Closed
@s0nx
fw/http_frame: Do not pass the data to upper layer (H2 parser)
8281c03 
if there was an error in a stream state transition

Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/http_parser: Added check for END_STREAM flag in trailer for h2 req
91897f3 
Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/http_parser: Remove redudant WARN_ON_ONCE() while dropping the req…
b6d06b1 
…uest

due to the duplicate header presence

Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/gfsm: Enabled debug prints
ce42940 
Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/http_stream: Permit sending immediate H2 reply in non half-closed …
0aba1a7 
…remote state

When request is blocked by Frang we might need to send the reply while in OPEN stream state

Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/hpack: Obtain :method value id from dynamic HPACK table entry when
7295db5 
          it cannot be determined using static table

Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/http_parser: Reset internal parser state after if-modified-since…
552ef1f 
… hdr parsing

Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/hpack: Change header field representation parsing logs
c84c38a 
to make it clear which particular encoding scheme is used

Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/http: Update comment sections
a3abb35 
Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/http_parser: Reformat code
dcd37d9 
Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx
fw/http_stream: Update copyright notice
1918efb 
Signed-off-by: Petr Vyazovik <[email protected]>
@s0nx s0nx merged commit 4f5b36e into master Nov 8, 2022
@s0nx s0nx deleted the pv-1387-h2-warn branch November 8, 2022 15:57
@RomanBelozerov RomanBelozerov mentioned this pull request Jan 11, 2023
Closed
@s0nx s0nx mentioned this pull request Jan 18, 2023
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@const-t const-t const-t approved these changes

@krizhanovsky krizhanovsky krizhanovsky approved these changes

Assignees

@s0nx s0nx

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

Warnings during h2 message exchanges
4 participants
@s0nx @const-t @RomanBelozerov @krizhanovsky