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

Fragmentation for h2 messages #1378

Closed
4 tasks
vankoven opened this issue Jan 10, 2020 · 8 comments
Closed
4 tasks

Fragmentation for h2 messages #1378

vankoven opened this issue Jan 10, 2020 · 8 comments

Comments

@vankoven
Copy link
Contributor

Scope

Amendment for #309 . The whole #309 is huge and general, so let's create a new issue for every new feature|bug request.

h2 requires framing. It's implemented already, but it's doesn't care about fragmentation. Remote peer will reject frames if they're bigger than remote peer allowed. By default maximum frame size is 16384 bytes, but client may enlarge that limit through SETTINGS frame.

When we forward messages to the client, we must honour that limits and fragment too big bodies and headers. I've added corresponding TODOs in #1374 PR

Since h2 is to be first-class citizen, we can store predefined response bodies in already fragmented and framed form. All clients must support frames of 16384 bytes and we don't need to adapt predefined response bodies for every clients.

Testing

Client must define different maximum frame sizes, responses mustn't use bigger frames. The following cases must be covered:

  • Fragmenting huge response bodies forwarded from HTTP/1.1 backends.
  • Fragmenting huge response headers forwarded from HTTP/1.1 backends.
  • Fragmenting huge response bodies generated by Tempesta (predefined responses).
  • Fragmenting huge response headers generated by Tempesta (predefined responses).
@vankoven
Copy link
Contributor Author

vankoven commented Mar 11, 2020

The issue is highly linked with #1379 , #488, h2-h2 proxying and #687 (comment).

Now we have combined logic for constucting h2 responses and framing them. And current logic looks like:

  • create HEADERS frame header, set required flags for stream/headers end
  • append all the required headers in HPACK encoding
  • append DATA frame header
  • append response body
  • send all the skbs and close the stream.

This approach doesn't respect not only the remote peer max_frame_size settings, but also remote peer receive window control. We have to split http and framing layers to fit the h2 proto requirements. Take a look at receive path, it's different: we have spit layers there, and we spit skbs not only on http massages borders, but also at h2 framing borders. So we need here.

My proposal:

Prepare h2 message without frame headers inside TfwHttpMsg before forwarding it to client. The message must have separate skbs for body and http headers, or at least a valid pointer to start of the body.

Then the resulting message is forwarded into tfw_h2_resp_fwd() function. The function calls the tfw_connection_send() hook (current behaviour). But tfw_connection_send() must be much more sophisticated than simple ss_send() witch pushes skbs into work queue.

tfw_connection_send() for h2 connections should receive unframed TfwHttpMessage, frame it according to current receive window, maximum frame size and TLS record size. And push it into ss_send(). Note, there is several cases, when the skb can't be sent to the connection and another attempt is required:

  • incomlete set of headers is sent to client: h2 forbids multiplexing when stream is in continuation state
  • current receive window is to small (or zero) to push a full frame. Pushing incomplete large HEADERS frame can cause head-of-line block for h2 connection.
    Thus we some times have to wake tfw_connection_send() up like we do for work queue.

Looking closely, it doesn't worth to make tfw_connection_send() so complex and I hate all that wake ups for too large number of objects. Instead we can improve work queue as I proposed in #687 (comment). The work queue will have much more work than simple tcp_push() actions. But we can play with h2 frames and effectively fit them into TCP frames. Even more, we can follow our own QoS settings and prioritize some streams (e.g. server streams over client ones). And we can implement pretty fair process for all streams inside singe connection.

The work queue will run jobs not for separate skb lists but for entire connections. Since there are a lot of multiplexed streams inside one connection, TfwConnection must be extended with fwd_queue. tfw_connection_send() will push a tuple (stream_id, message) into it and work queue will send the queue.

With this change in mind, proxy mode of operation for h2 connection (without full assembling) will be very easy to implement: just push a new message into connection, and show it's incomplete. If a new message part is processed, lock it. Work queue will skip locked streams and proceed with ready ones.

To sum up every thing, the full proposal is huge. But I can't see a good way to implement outgoing framing in the right way with cheaper costs.

@krizhanovsky
Copy link
Contributor

I have only objection that the proposed architecture doesn't account TCP HoL blocking (see #1196) and potentially racy: if we prepare frames on tfw_connection_send() and queue them for transmission, then a client may send us smaller value in WINDOW_UPDATE before we transmit just framed HTTP message (assume that send queue is long enough).

The point is that we can frame data on receive window update (for HTTP/2, TCP, and QUIC), just like the Linux skb coalescing works - if we do this asynchronously, then the things can be broken. We had the same problem with TLS records slicing and made a solution.

@vankoven
Copy link
Contributor Author

vankoven commented Mar 19, 2020

I have reviewed the approach. It must be done in several stages without trying to beat everything at once. First stage - implement correct framing and remove chunked encoding for h2 connections. Second stage - h2 flow control. Third - prioritization.

First stage: framing

No hard changes are required, but #1378 and #1379 will be fixed.

Remove chunked encoding

Chunked encoding can't be be forwarded to h2-receivers. It is possible to remove the encoding either on receive or on transmit path. Usually it make sense to postpone heavy processing as far as possible, but stripping chunked encoding on transmit path doesn't give any advantages. In the same time it worth to strip the chunked encoding just before saving response to cache. In this case we will postpone fragmentation operation until block or forward decision is made and no 'de-chunking' will be required for responses served from cache.

To accomplish that we need a new function int tfw_http_msg_rm_chunked(TfwHttpMsg *). The function will iterate over body chunks, cut off chunk descriptors, and update body string. The Http Parser must put chunk descriptors into separate TfwStr chunks of the body and mark with TFW_STR_NAME flag.

Currently we will need the function only for responses and we always know, that response will be used for http2 client. After full h2-proxy mode will be implemented the function can be used for stripping chunked encoding from requests before forwarding to h2 server connections.

Alternative: While parsing a response, don't put all the body chunk descriptors into TfwHttpMsg->body but put them into some to_strip string. In this case we won't need to iterate over all body chunks during removing chunked encoding. Normally we prefer not to run over and over the same collections again and again, and the alternative approach seems fine. But it won't work for requests, since we don't know output connection during message parsing, like we do for responses. Thus we still will need int tfw_http_msg_rm_chunked(TfwHttpMsg *) and all that logic. With this in mind I prefer to leave parser as clean as possible and use usual scenario.

After chunked encoding is stripped from the body, all we need to do - frame the body as usual for http/2 connections.

Frame http/2 messages

Message framing should happen in ss_tx_action() context. for correct framing we need:

  • h2 settings of target peer: maximum frame size, maximum window size and so on.
  • information about start of body part in http message.
  • targert stream id.

Thus it's not enough to use skb list and flags as only arguments for ss_do_send(). What we should do - reimplement conn_send callbak (ss_send() function). Instead of passing skb_head we must pass TfwHttpMsg and stream_id to lower levels.

Since previously we pushed cloned skbs or detached from message skbs to lower levels, there was no issues about life time: we could simply free skbs. No we have to implement reference counters inside TfwHttpMsg.

Message framing will take place in ss_do_send(): knowing right allowed sizes we can form frames in right way. Previously chunked messages are not chunked at this stage any more. After message is sent, the h2 state machine will be triggered and the stream will be removed. We already have this logic but on receive side. Nothing changes here.

At this stage we don't need to care about TLS frame sizes, mss and other things.

Generally speaking, nothing in Tempesta's behaviour will be changed. The WorkQueue egress scheduler will have the same prioritisation: simple queue.

Tests: current test infrastracture doesn't support h2 messages, h2spec is not designed for that, but we can use curl to load resources: if framing is incorrect or has bad transfer-encoding, the response will be filtered out and error is returned.

Time estimation: 1 week +- 1 day.

Second stage: flow control

Flow control can be implemented independently from the framing (but previously I thought an other way). This is the greatest part of the job.

With h2 we have THREE flow controls:

  • TCP flow control. Works at kernel level and we don't need to carry about it at all.
  • H2 connection level flow control. We can't push more DATA frames than allowed for whole connection.
  • H2 stream level flow control. We can't push more DATA frames than allowed for stream.

Note, that only DATA frames is subject for flow control.

When a flow control for a single stream is exhausted, we can continue to other stream. When total flow control is exhausted, we have to wait for WINDOW_UPDATE frame. There was notice about race conditions for windows sizes. H2 specification allows receiver to push smaller window sizes at any time, but the receiver must be aware of that races and should receive frames of previous sizes. Since transmission happens from the same cpu, we don't need to care about synchronization here.

We don't need to take care about TCP window size. It can be smaller or bigger than the h2 window size. It's generally OK: while TCP window size is used by kernels on sender and receiver to check that no data loss happen and no retransmission required, h2 flow control allows to synchronise performance and buffers between h2 applications.

Here we have caveats. We need to switch between h2 streams for one connections and chose one against others. This only possible, when WorkQueue works not with single messages in queue manner, but with connections with egress stream queues. When the h2 receive buffers are exhausted, transmission must be paused until free space appears. (Responses without bodies can be sent out without any flow control). This is exactly #687 (comment) proposal.

With this in mind the req_fwd() and resp_fwd() routines will be actually moved to transmit path. Actually I find it as OK: no we have possible reschedule loops in forwarding code (and counters to break that loops). After implementation, rescheduling will be called less times.

The biggest challenge: effective new WorkQueue implementation.

Tests: h2spec has some tests, but i'm not sure this going to be enough. Also performance tests are required.

Time estimation: 2+ weeks.

Third stage: prioritization

Once second stage is done, all we need - change list of streams ready to transmit to some other structure, that allow us to chose streams depending on their priority. It reimplements only one function from the previous stage, but it sophisticated enough to me split into separate stage.

@krizhanovsky
Copy link
Contributor

I agree that it makes sense to store HTTP responses in the cache with removed chunked encoding.

To accomplish that we need a new function int tfw_http_msg_rm_chunked(TfwHttpMsg *). The function will iterate over body chunks, cut off chunk descriptors, and update body string.

Why not to remove the encoding right during reading the response body and parsing the chunked encoding?

  1. responses can be quite large and iteration can hurt
  2. in-place removing of the encoding will get some foundation for HTTP message buffering and streaming #498

While on HTTP parsing stage in tfw_http_parse_resp() we already called tfw_http_resp_pair(), so we know the request protocol (whether it's h2 or HTTP/1), so we could not to remove chunked encoding for HTTP/1 clients to avoid the extra work, I believe it doesn't make sense because HTTP/1 is legacy.

The Http Parser must put chunk descriptors into separate TfwStr chunks of the body and mark with TFW_STR_NAME flag.

Agree. The chunked encoding encodes chunks, i.e. it's quite likely that we have separate chunks in separate skbs, i.e. in the fast path code we can just move skb head and tail pointers to remove the chunked encoding (for the chunk length and trailing `\r\n' correspondingly) if we do this on reading stage.

But it won't work for requests, since we don't know output connection during message parsing, like we do for responses.

#1125 even not scheduled for any of the releases. Also HTTP/1 client and HTTP/2 server is quite a corner case and in this case we can do the same - just remove chunked encoding for all requests and add it back if an upstream doesn't support HTTP/2.

Message framing should happen in ss_tx_action() context.

Why not in context of sk_write_xmit()? That's the point where we know the current state of TCP windows and how much data we can transmit and the peer can read.

At this stage we don't need to care about TLS frame sizes, mss and other things.

Why? I think we should care about TCP state. Suppose HTTP/2 allows to send 4KB frame. If TCP congestion window is say 2KB, then half of the HTTP/2 frame will stuck in our send queue. If TCP receive window announced by the peer is 2KB, then, the same way, the second half of the frame will be sitting in our send queue and waiting for the peer ACKs. See https://www.slideshare.net/kazuho/reorganizing-website-architecture-for-http2-and-beyond

TCP flow control. Works at kernel level and we don't need to carry about it at all.
...
We don't need to take care about TCP window size. It can be smaller or bigger than the h2 window size. It's generally OK: while TCP window size is used by kernels on sender and receiver to check that no data loss happen and no retransmission required, h2 flow control allows to synchronise performance and buffers between h2 applications.

We do need to carry about this, see above. The things will work, but clients will receive responses with large latency. Kazuho described the problem quite clearly.

When total flow control is exhausted, we have to wait for WINDOW_UPDATE frame.

Need to check the scenario carefully, but in my assumption at the moment we have following scenario:

  1. send some, maybe the whole message, DATA using ss_do_send(), which leads to TCP call tcp_write_xmit(). Suppose at this moment we can send only part of data.
  2. we receive TCP ACK, maybe with HTTP/2 WINDOW_UPDATE frame.
  3. On receiving ACK TCP calls tcp_write_xmit() again, so our callback for HTTP/2 (as we have tfw_tls_encrypt() for TLS now) can be called and we must check how much data can be sent to the peer according to HTTP/2 flow control.

The key point is whether sk_data_ready() callback is called in TCP ACK processing logic (see tcp_ack()) before calling tcp_write_xmit(). If so, then we're good and we can prepare the next HTTP frame on the tcp_write_xmit() callback with the knowledge of the current HTTP/2 flow control state. Otherwise we'll need to take some additional effort.

Actually, the requirement from #1196

It seems to avoid TCP HoL blocking, we should move HTTP/2 fragmentation into TLS layer (just as we form TLS records by a TCP callbak). See Reorganizing Website Architecture for HTTP/2 and Beyond slides 15-20.

must be done in this issue. There is nothing in common between the prioritization and TCP HoL blocking actually.

With this in mind the req_fwd() and resp_fwd() routines will be actually moved to transmit path.

Not necessary. This seems required change for #687 (comment) , but I don't see why we need to do this in context for the task. tfw_h2_resp_fwd() and tfw_http_req_fwd() just move an HTTP message to a proper HTTP connection. They can lead to ss_send(), but actual transmission is still happen in tcp_write_xmit().

Third stage: prioritization

We have separate #1196. For now we can send DATA frames consequently or in round-robin fashion. Also

When a flow control for a single stream is exhausted, we can continue to other stream.

is a good strategy for now to schedule DATA frames from different streams.

@vankoven
Copy link
Contributor Author

The HLD was actively discussed in the chat and we agreed to postpone flow control implementation. The only thing required for now - fix http2 message framing to produce frames that doesn't overflow remote peer settings (See functions tfw_h2_make_frames() and tfw_cache_build_resp() ).

The proposed solution requires architecture change, but not all the desires (some of them was pretty old) was taken into account. Thus we preferred a quick fix now rather than big architecture rework.

It seems like we don't need to implement flow control right away, since modern browsers doesn't use per-stream flow control and use pretty big receive windows as per-connection flow control limits.

@krizhanovsky
Copy link
Contributor

Tried to load tempesta-tech.com content with Chrome and Firefox several times with following configuration:

listen 192.168.100.4:443 proto=h2;srv_group default {
	server 127.0.0.1:8080;
}
vhost debian {
	tls_certificate /root/tempesta/etc/tfw-root.crt;
	tls_certificate_key /root/tempesta/etc/tfw-root.key;	proxy_pass default;
}cache 1;
cache_fulfill * *;http_chain {
	-> debian;
}

One time I saw empty page, but probably that was issues with cache in the browser. Next tries succeeded, but I saw following issues in dmesg:

[12787.497226] [tempesta fw] modules are started
[12795.649644] [tempesta fw] Warning: HTTP/2 request dropped: state=Req_HdrPseudo input=0x64('dnt'), len=3, off=0
[12795.653180] [tempesta fw] Warning: failed to parse request: 192.168.100.1:443
[12812.288877] ------------[ cut here ]------------
[12812.292588] WARNING: CPU: 1 PID: 761 at /root/tempesta/tempesta_fw/hpack.c:2391 tfw_hpack_node_compare+0xc08/0xc30 [tempesta_fw]
[12812.299003] Modules linked in: tempesta_fw(O) tempesta_db(O) tempesta_tls(O) tempesta_lib(O) binfmt_misc crct10dif_pclmul bochs_drm ttm drm_kms_helper drm ppdev sg parport_pc fb_sys_fops parport serio_raw syscopyarea sysfillrect sysimgblt button ip_tables x_tables ext4 crc16 mbcache jbd2 fscrypto sr_mod cdrom sd_mod ata_generic ata_piix psmouse libata e1000 i2c_piix4 scsi_mod [last unloaded: tempesta_lib]
[12812.315174] CPU: 1 PID: 761 Comm: apache2 Tainted: G           O    4.14.32-kdump+ #148
[12812.320028] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS ?-20190727_073836-buildvm-ppc64le-16.ppc.fedoraproject.org-3.fc31 04/01/2014
[12812.326725] task: ffff99c76fb89000 task.stack: ffff99c76fad8000
[12812.329588] RIP: 0010:tfw_hpack_node_compare+0xc08/0xc30 [tempesta_fw]
[12812.332590] RSP: 0018:ffff99c77fd037b0 EFLAGS: 00010293
[12812.336248] RAX: ffff99c768f321c6 RBX: 000000000000001f RCX: 0000000000000029
[12812.339508] RDX: ffff99c77fd222bf RSI: 0000000000000029 RDI: ffff99c77fd038a0
[12812.342448] RBP: 000000000000001f R08: 0000000000000029 R09: 0000000000002e30
[12812.346101] R10: 0000000000000003 R11: ffff99c77fd03900 R12: 0000000000000000
[12812.353310] R13: 0000000000002e30 R14: 0000000000002030 R15: 0000000000000000
[12812.356917] FS:  00007ff65e7f4700(0000) GS:ffff99c77fd00000(0000) knlGS:0000000000000000
[12812.360021] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[12812.362257] CR2: 00007ff670f41000 CR3: 00000000708e0003 CR4: 00000000003606e0
[12812.364552] Call Trace:
[12812.367388]  <IRQ>
[12812.370085]  tfw_hpack_encode+0x146/0x630 [tempesta_fw]
[12812.372985]  tfw_h2_add_hdr_via+0xea/0x130 [tempesta_fw]
[12812.375326]  tfw_http_resp_cache_cb+0x4a7/0x5e0 [tempesta_fw]
[12812.377573]  ? __tfw_http_msg_add_str_data+0x59/0x100 [tempesta_fw]
[12812.379916]  ? tfw_http_conn_drop+0x250/0x250 [tempesta_fw]
[12812.382522]  tfw_cache_process+0x6d/0x290 [tempesta_fw]
[12812.385932]  ? tfw_gfsm_move+0x146/0x180 [tempesta_fw]
[12812.388946]  ? recalibrate_cpu_khz+0x10/0x10
[12812.391393]  tfw_http_resp_cache+0xdc/0x150 [tempesta_fw]
[12812.393519]  tfw_http_msg_process_generic+0x849/0xcf0 [tempesta_fw]
[12812.395639]  ? __dev_queue_xmit+0x2eb/0x7a0
[12812.397337]  ? pg_skb_alloc+0x223/0x420
[12812.399892]  tfw_http_msg_process+0x7f/0xc0 [tempesta_fw]
[12812.403147]  __gfsm_fsm_exec+0x51/0x90 [tempesta_fw]
[12812.405678]  ? consume_skb+0x22/0x80
[12812.407523]  tfw_connection_recv+0x3c/0x60 [tempesta_fw]
[12812.410604]  ? tfw_connection_send+0x20/0x20 [tempesta_fw]
[12812.412500]  ss_tcp_process_data+0x1e5/0x480 [tempesta_fw]
[12812.414356]  ? tcp_transmit_skb+0x530/0x9c0
[12812.417273]  ss_tcp_data_ready+0x3e/0x90 [tempesta_fw]
[12812.420634]  tcp_rcv_established+0x4cd/0x570
[12812.422982]  tcp_v4_do_rcv+0x124/0x1c0
[12812.424900]  tcp_v4_rcv+0x93f/0xa40
[12812.426584]  ip_local_deliver_finish+0x95/0x1c0
[12812.428236]  ip_local_deliver+0x66/0xe0
[12812.429746]  ? nf_hook_slow+0x3e/0xc0
[12812.431236]  ip_rcv+0x284/0x3b0
[12812.433766]  ? inet_del_offload+0x30/0x30
[12812.436675]  __netif_receive_skb_core+0x84a/0xb30
[12812.439918]  ? e1000_clean+0x34d/0x8c0 [e1000]
[12812.442004]  ? process_backlog+0x92/0x120
[12812.443862]  process_backlog+0x92/0x120
[12812.445621]  net_rx_action+0x261/0x3a0
[12812.447176]  __do_softirq+0x104/0x297
[12812.449739]  do_softirq_own_stack+0x2a/0x40
[12812.453302]  </IRQ>
[12812.454846]  do_softirq.part.17+0x2a/0x30
[12812.456481]  __local_bh_enable_ip+0x4b/0x50
[12812.458097]  ip_finish_output2+0x1ae/0x380
[12812.459435]  ? ip_output+0x6c/0xe0
[12812.460634]  ip_output+0x6c/0xe0
[12812.461792]  ? ip_queue_xmit+0x57/0x3b0
[12812.463260]  tcp_transmit_skb+0x530/0x9c0
[12812.464905]  tcp_write_xmit+0x21e/0x11c0
[12812.467517]  ? _copy_from_iter_full+0x93/0x230
[12812.470404]  __tcp_push_pending_frames+0x28/0x90
[12812.473270]  tcp_sendmsg_locked+0x689/0xe60
[12812.475806]  tcp_sendmsg+0x22/0x40
[12812.477962]  sock_sendmsg+0x31/0x40
[12812.480112]  sock_write_iter+0x82/0xf0
[12812.482220]  do_iter_readv_writev+0x116/0x180
[12812.484886]  do_iter_write+0x7b/0x180
[12812.487287]  vfs_writev+0x93/0x110
[12812.489053]  ? vm_mmap_pgoff+0xe7/0x120
[12812.490378]  ? do_writev+0x59/0xf0
[12812.491807]  do_writev+0x59/0xf0
[12812.493675]  do_syscall_64+0x61/0x110
[12812.495703]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[12812.498013] RIP: 0033:0x7ff6702890cd
[12812.500314] RSP: 002b:00007ff65e7f36e0 EFLAGS: 00000293 ORIG_RAX: 0000000000000014
[12812.503638] RAX: ffffffffffffffda RBX: 0000000000007b20 RCX: 00007ff6702890cd
[12812.506450] RDX: 0000000000000002 RSI: 00007ff65e7f3810 RDI: 0000000000000009
[12812.509581] RBP: 00007ff670ee20b0 R08: 00007ff670ee2910 R09: 00007ff670ee2348
[12812.512483] R10: 0000000000000001 R11: 0000000000000293 R12: 0000000000000002
[12812.514542] R13: 00007ff65e7f3810 R14: 00007ff65e7f3770 R15: 00007ff670f4d560
[12812.517896] Code: ff 66 85 db 0f 84 03 f7 ff ff 83 3c 24 00 0f 85 25 f9 ff ff e9 84 f8 ff ff 66 45 85 d2 4c 89 ca 0f 85 77 f8 ff ff e9 e2 f6 ff ff <0f> 0b e9 ed fb ff ff 4c 8b 7c 24 20 4c 8b 54 24 28 4d 89 17 49
[12812.525742] ---[ end trace 097e1a9dcfb5e9a4 ]---
[12814.171755] [tempesta fw] HTTP/2 connection is closed by client with error code: 1, ID of last processed stream: 0
[12814.179786] ------------[ cut here ]------------
[12814.181782] WARNING: CPU: 0 PID: 7 at /root/tempesta/tempesta_fw/http_frame.c:231 tfw_h2_context_clear+0x10/0x20 [tempesta_fw]
[12814.186365] Modules linked in: tempesta_fw(O) tempesta_db(O) tempesta_tls(O) tempesta_lib(O) binfmt_misc crct10dif_pclmul bochs_drm ttm drm_kms_helper drm ppdev sg parport_pc fb_sys_fops parport serio_raw syscopyarea sysfillrect sysimgblt button ip_tables x_tables ext4 crc16 mbcache jbd2 fscrypto sr_mod cdrom sd_mod ata_generic ata_piix psmouse libata e1000 i2c_piix4 scsi_mod [last unloaded: tempesta_lib]
[12814.207802] CPU: 0 PID: 7 Comm: ksoftirqd/0 Tainted: G        W  O    4.14.32-kdump+ #148
[12814.212608] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS ?-20190727_073836-buildvm-ppc64le-16.ppc.fedoraproject.org-3.fc31 04/01/2014
[12814.220049] task: ffff99c761fef1c0 task.stack: ffff99c762440000
[12814.222970] RIP: 0010:tfw_h2_context_clear+0x10/0x20 [tempesta_fw]
[12814.225685] RSP: 0018:ffff99c762443d88 EFLAGS: 00010202
[12814.227865] RAX: ffffffffc059e740 RBX: ffff99c7661d7190 RCX: ffffd71041c2a91f
[12814.230369] RDX: 0000000000000015 RSI: ffff99c762912640 RDI: ffff99c7661d78b0
[12814.234269] RBP: ffff99c7661d78b0 R08: 0000000000000000 R09: ffff99c762912641
[12814.238156] R10: ffff99c762443c48 R11: 00000000658522fc R12: ffff99c7661d7500
[12814.241717] R13: ffffffffc05f6748 R14: ffff99c77fc21e80 R15: ffff99c76619d400
[12814.244328] FS:  0000000000000000(0000) GS:ffff99c77fc00000(0000) knlGS:0000000000000000
[12814.247125] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[12814.250285] CR2: 00007ff67104b000 CR3: 0000000060e0a003 CR4: 00000000003606f0
[12814.253796] Call Trace:
[12814.255830]  tfw_tls_conn_dtor+0xe3/0x1a0 [tempesta_fw]
[12814.258301]  ss_tx_action+0x432/0x570 [tempesta_fw]
[12814.260850]  ? __switch_to_asm+0x34/0x70
[12814.262699]  ? __switch_to_asm+0x40/0x70
[12814.264539]  ? __switch_to_asm+0x34/0x70
[12814.267602]  ? __switch_to_asm+0x40/0x70
[12814.271380]  ? __switch_to_asm+0x34/0x70
[12814.274064]  ? __switch_to_asm+0x34/0x70
[12814.276587]  ? __switch_to_asm+0x34/0x70
[12814.279018]  net_tx_action+0x8d/0x1b0
[12814.281565]  __do_softirq+0x104/0x297
[12814.284810]  run_ksoftirqd+0x14/0x30
[12814.287583]  smpboot_thread_fn+0x109/0x160
[12814.290081]  kthread+0xfa/0x130
[12814.292696]  ? sort_range+0x20/0x20
[12814.295328]  ? kthread_create_on_node+0x60/0x60
[12814.298501]  ret_from_fork+0x35/0x40
[12814.301701] Code: ff 7f c7 43 10 ff ff ff 7f 5b e9 bc 30 05 00 66 90 66 2e 0f 1f 84 00 00 00 00 00 48 83 7f 38 00 75 09 48 83 c7 68 e9 80 31 05 00 <0f> 0b 48 83 c7 68 e9 75 31 05 00 0f 1f 44 00 00 48 81 ec 88 00
[12814.310644] ---[ end trace 097e1a9dcfb5e9a5 ]---
[12844.556945] [tempesta fw] Warning: HTTP/2 request dropped: state=Req_HdrPseudo input=0x64('dnt'), len=3, off=0
[12844.561419] [tempesta fw] Warning: failed to parse request: 192.168.100.1:443
[12870.932752] [tempesta fw] HTTP/2 connection is closed by client with error code: 1, ID of last processed stream: 0
[12925.294867] [tempesta fw] HTTP/2 connection is closed by client with error code: 9, ID of last processed stream: 0
[12951.461356] [tempesta fw] HTTP/2 connection is closed by client with error code: 9, ID of last processed stream: 0

Please check whether it's related to the #1400 pull request and, if not, create a separate issue for the problem.

@vankoven
Copy link
Contributor Author

The first trace is not related to #1400, It also reproduces to me on current master, #1387 (comment)

But the second is a new to me. And multiple connections close with real browser request parsing failure is also a new thing. I'll check that.

@vankoven
Copy link
Contributor Author

Fixed by #1400

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

No branches or pull requests

2 participants