search

StarRocks / starrocks

The world's fastest open query engine for sub-second analytics both on and off the data lakehouse. With the flexibility to support nearly any scenario, StarRocks provides best-in-class performance for multi-dimensional analytics, real-time analytics, and ad-hoc queries. A Linux Foundation project.
https://starrocks.io
Apache License 2.0
8.9k stars 1.78k forks source link

[FE] FE processing 100-Continue requests with connection keepalive, causes subsequent http request parse failure #52516

Open kevincai opened 1 day ago

kevincai commented 1 day ago

Steps to reproduce the behavior (Required)

  1. Create a java maven project with the example test code StarRocksStreamLoad.java.txt
  2. start a starrocks cluster with allin1 image docker run -d -it --rm -p 9030:9030 -p 8030:8030 -p 8040:8040 starrocks/allin1-ubuntu:3.2.8

  3. connect to starrocks fe with mysql client and create the database and table

    CREATE DATABASE tdtest;

USE tdtest;

CREATE TABLE `stream_test` (
`id` bigint(20) COMMENT "",
`id2` bigint(20) COMMENT "",
`username` varchar(32) COMMENT ""
) ENGINE=OLAP
DUPLICATE KEY(`id`)
DISTRIBUTED BY HASH(`id`) BUCKETS 20;
    1. Run the streamload testing.

Expected behavior (Required)

All the http requests should be successful, even though the response will say that the given label already exists.

Real behavior (Required)

FE reports bad request. accept bad request: /bad-request, error: text is empty (possibly HTTP/0.9)

StarRocks version (Required)

kevincai commented 1 day ago

An example output from test client

Content:1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
{
    "TxnId": -1,
    "Label": "39c25a5c-7000-496e-a98e-348a264c81df",
    "Status": "Label Already Exists",
    "ExistingJobStatus": "FINISHED",
    "Message": "Label [39c25a5c-7000-496e-a98e-348a264c81df] has already been used.",
    "NumberTotalRows": 0,
    "NumberLoadedRows": 0,
    "NumberFilteredRows": 0,
    "NumberUnselectedRows": 0,
    "LoadBytes": 0,
    "LoadTimeMs": 0,
    "BeginTxnTimeMs": 0,
    "StreamLoadPlanTimeMs": 0,
    "ReadDataTimeMs": 0,
    "WriteDataTimeMs": 0,
    "CommitAndPublishTimeMs": 0
}
Content:1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
1   10  Simon
Exception in thread "main" java.io.IOException: Stream load failed, statusCode=400 load result=Bad Request. <br/> text is empty (possibly HTTP/0.9)
    at org.example.StarRocksStreamLoad.sendData(StarRocksStreamLoad.java:134)
    at org.example.StarRocksStreamLoad.main(StarRocksStreamLoad.java:165)

Process finished with exit code 1
kevincai commented 1 day ago

Sample tcpdump for the interaction.

reading from file streamload.tcpdump, link-type EN10MB (Ethernet), snapshot length 262144
02:01:55.231368 IP 192.168.65.1.52109 > 172.17.0.2.8030: Flags [S], seq 3244812941, win 65408, options [mss 65495,nop,nop,TS val 3488305546 ecr 0,nop,wscale 7], length 0
    0x0000:  4500 003c 14f0 0000 3f06 b90f c0a8 4101  E..<....?.....A.
    0x0010:  ac11 0002 cb8d 1f5e c167 ea8d 0000 0000  .......^.g......
    0x0020:  a002 ff80 5598 0000 0204 ffd7 0101 080a  ....U...........
    0x0030:  cfeb 518a 0000 0000 0103 0307            ..Q.........
02:01:55.231539 IP 172.17.0.2.8030 > 192.168.65.1.52109: Flags [S.], seq 3800569226, ack 3244812942, win 33280, options [mss 65495,nop,nop,TS val 3960569485 ecr 3488305546,nop,wscale 7], length 0
    0x0000:  4500 003c 0000 4000 4006 8cff ac11 0002  E..<..@.@.......
    0x0010:  c0a8 4101 1f5e cb8d e288 158a c167 ea8e  ..A..^.......g..
    0x0020:  a012 8200 adeb 0000 0204 ffd7 0101 080a  ................
    0x0030:  ec11 7e8d cfeb 518a 0103 0307            ..~...Q.....
02:01:55.232128 IP 192.168.65.1.52109 > 172.17.0.2.8030: Flags [.], ack 1, win 511, options [nop,nop,TS val 3488305547 ecr 3960569485], length 0
    0x0000:  4500 0034 5de8 0000 3f06 701f c0a8 4101  E..4]...?.p...A.
    0x0010:  ac11 0002 cb8d 1f5e c167 ea8e e288 158b  .......^.g......
    0x0020:  8010 01ff 5598 0000 0101 080a cfeb 518b  ....U.........Q.
    0x0030:  ec11 7e8d                                ..~.
02:01:55.234543 IP 192.168.65.1.52109 > 172.17.0.2.8030: Flags [P.], seq 1:342, ack 1, win 4096, options [nop,nop,TS val 3488305550 ecr 3960569485], length 341
    0x0000:  4500 0189 43fc 0000 3f06 88b6 c0a8 4101  E...C...?.....A.
    0x0010:  ac11 0002 cb8d 1f5e c167 ea8e e288 158b  .......^.g......
    0x0020:  8018 1000 5598 0000 0101 080a cfeb 518e  ....U.........Q.
    0x0030:  ec11 7e8d 5055 5420 2f61 7069 2f74 6474  ..~.PUT./api/tdt
    0x0040:  6573 742f 7374 7265 616d 5f74 6573 742f  est/stream_test/
    0x0050:  5f73 7472 6561 6d5f 6c6f 6164 2048 5454  _stream_load.HTT
    0x0060:  502f 312e 310d 0a45 7870 6563 743a 2031  P/1.1..Expect:.1
    0x0070:  3030 2d63 6f6e 7469 6e75 650d 0a41 7574  00-continue..Aut
    0x0080:  686f 7269 7a61 7469 6f6e 3a20 4261 7369  horization:.Basi
    0x0090:  6320 636d 3976 6444 6f3d 0d0a 6c61 6265  c.cm9vdDo=..labe
    0x00a0:  6c3a 2033 3963 3235 6135 632d 3730 3030  l:.39c25a5c-7000
    0x00b0:  2d34 3936 652d 6139 3865 2d33 3438 6132  -496e-a98e-348a2
    0x00c0:  3634 6338 3164 660d 0a43 6f6e 7465 6e74  64c81df..Content
    0x00d0:  2d4c 656e 6774 683a 2031 3039 0d0a 436f  -Length:.109..Co
    0x00e0:  6e74 656e 742d 5479 7065 3a20 7465 7874  ntent-Type:.text
    0x00f0:  2f70 6c61 696e 3b20 6368 6172 7365 743d  /plain;.charset=
    0x0100:  5554 462d 380d 0a48 6f73 743a 2031 3237  UTF-8..Host:.127
    0x0110:  2e30 2e30 2e31 3a38 3033 300d 0a43 6f6e  .0.0.1:8030..Con
    0x0120:  6e65 6374 696f 6e3a 204b 6565 702d 416c  nection:.Keep-Al
    0x0130:  6976 650d 0a55 7365 722d 4167 656e 743a  ive..User-Agent:
    0x0140:  2041 7061 6368 652d 4874 7470 436c 6965  .Apache-HttpClie
    0x0150:  6e74 2f34 2e35 2e33 2028 4a61 7661 2f31  nt/4.5.3.(Java/1
    0x0160:  312e 302e 3229 0d0a 4163 6365 7074 2d45  1.0.2)..Accept-E
    0x0170:  6e63 6f64 696e 673a 2067 7a69 702c 6465  ncoding:.gzip,de
    0x0180:  666c 6174 650d 0a0d 0a                   flate....
02:01:55.234555 IP 172.17.0.2.8030 > 192.168.65.1.52109: Flags [.], ack 342, win 258, options [nop,nop,TS val 3960569488 ecr 3488305550], length 0
    0x0000:  4500 0034 d765 4000 4006 b5a1 ac11 0002  E..4.e@.@.......
    0x0010:  c0a8 4101 1f5e cb8d e288 158b c167 ebe3  ..A..^.......g..
    0x0020:  8010 0102 ade3 0000 0101 080a ec11 7e90  ..............~.
    0x0030:  cfeb 518e                                ..Q.
02:01:55.246660 IP 172.17.0.2.8030 > 192.168.65.1.52109: Flags [P.], seq 1:173, ack 342, win 260, options [nop,nop,TS val 3960569500 ecr 3488305550], length 172
    0x0000:  4500 00e0 d766 4000 4006 b4f4 ac11 0002  E....f@.@.......
    0x0010:  c0a8 4101 1f5e cb8d e288 158b c167 ebe3  ..A..^.......g..
    0x0020:  8018 0104 ae8f 0000 0101 080a ec11 7e9c  ..............~.
    0x0030:  cfeb 518e 4854 5450 2f31 2e31 2033 3037  ..Q.HTTP/1.1.307
    0x0040:  2054 656d 706f 7261 7279 2052 6564 6972  .Temporary.Redir
    0x0050:  6563 740d 0a63 6f6e 7465 6e74 2d6c 656e  ect..content-len
    0x0060:  6774 683a 2030 0d0a 6c6f 6361 7469 6f6e  gth:.0..location
    0x0070:  3a20 6874 7470 3a2f 2f31 3237 2e30 2e30  :.http://127.0.0
    0x0080:  2e31 3a38 3034 302f 6170 692f 7464 7465  .1:8040/api/tdte
    0x0090:  7374 2f73 7472 6561 6d5f 7465 7374 2f5f  st/stream_test/_
    0x00a0:  7374 7265 616d 5f6c 6f61 640d 0a63 6f6e  stream_load..con
    0x00b0:  7465 6e74 2d74 7970 653a 2074 6578 742f  tent-type:.text/
    0x00c0:  6874 6d6c 0d0a 636f 6e6e 6563 7469 6f6e  html..connection
    0x00d0:  3a20 6b65 6570 2d61 6c69 7665 0d0a 0d0a  :.keep-alive....
02:01:55.247073 IP 192.168.65.1.52109 > 172.17.0.2.8030: Flags [.], ack 173, win 4094, options [nop,nop,TS val 3488305562 ecr 3960569500], length 0
    0x0000:  4500 0034 fedc 0000 3f06 cf2a c0a8 4101  E..4....?..*..A.
    0x0010:  ac11 0002 cb8d 1f5e c167 ebe3 e288 1637  .......^.g.....7
    0x0020:  8010 0ffe 5598 0000 0101 080a cfeb 519a  ....U.........Q.
    0x0030:  ec11 7e9c                                ..~.
02:01:56.280400 IP 192.168.65.1.52109 > 172.17.0.2.8030: Flags [P.], seq 342:683, ack 173, win 4096, options [nop,nop,TS val 3488306595 ecr 3960569500], length 341
    0x0000:  4500 0189 9ffd 0000 3f06 2cb5 c0a8 4101  E.......?.,...A.
    0x0010:  ac11 0002 cb8d 1f5e c167 ebe3 e288 1637  .......^.g.....7
    0x0020:  8018 1000 5598 0000 0101 080a cfeb 55a3  ....U.........U.
    0x0030:  ec11 7e9c 5055 5420 2f61 7069 2f74 6474  ..~.PUT./api/tdt
    0x0040:  6573 742f 7374 7265 616d 5f74 6573 742f  est/stream_test/
    0x0050:  5f73 7472 6561 6d5f 6c6f 6164 2048 5454  _stream_load.HTT
    0x0060:  502f 312e 310d 0a45 7870 6563 743a 2031  P/1.1..Expect:.1
    0x0070:  3030 2d63 6f6e 7469 6e75 650d 0a41 7574  00-continue..Aut
    0x0080:  686f 7269 7a61 7469 6f6e 3a20 4261 7369  horization:.Basi
    0x0090:  6320 636d 3976 6444 6f3d 0d0a 6c61 6265  c.cm9vdDo=..labe
    0x00a0:  6c3a 2033 3963 3235 6135 632d 3730 3030  l:.39c25a5c-7000
    0x00b0:  2d34 3936 652d 6139 3865 2d33 3438 6132  -496e-a98e-348a2
    0x00c0:  3634 6338 3164 660d 0a43 6f6e 7465 6e74  64c81df..Content
    0x00d0:  2d4c 656e 6774 683a 2031 3039 0d0a 436f  -Length:.109..Co
    0x00e0:  6e74 656e 742d 5479 7065 3a20 7465 7874  ntent-Type:.text
    0x00f0:  2f70 6c61 696e 3b20 6368 6172 7365 743d  /plain;.charset=
    0x0100:  5554 462d 380d 0a48 6f73 743a 2031 3237  UTF-8..Host:.127
    0x0110:  2e30 2e30 2e31 3a38 3033 300d 0a43 6f6e  .0.0.1:8030..Con
    0x0120:  6e65 6374 696f 6e3a 204b 6565 702d 416c  nection:.Keep-Al
    0x0130:  6976 650d 0a55 7365 722d 4167 656e 743a  ive..User-Agent:
    0x0140:  2041 7061 6368 652d 4874 7470 436c 6965  .Apache-HttpClie
    0x0150:  6e74 2f34 2e35 2e33 2028 4a61 7661 2f31  nt/4.5.3.(Java/1
    0x0160:  312e 302e 3229 0d0a 4163 6365 7074 2d45  1.0.2)..Accept-E
    0x0170:  6e63 6f64 696e 673a 2067 7a69 702c 6465  ncoding:.gzip,de
    0x0180:  666c 6174 650d 0a0d 0a                   flate....
02:01:56.288739 IP 172.17.0.2.8030 > 192.168.65.1.52109: Flags [P.], seq 173:298, ack 683, win 260, options [nop,nop,TS val 3960570542 ecr 3488306595], length 125
    0x0000:  4500 00b1 d767 4000 4006 b522 ac11 0002  E....g@.@.."....
    0x0010:  c0a8 4101 1f5e cb8d e288 1637 c167 ed38  ..A..^.....7.g.8
    0x0020:  8018 0104 ae60 0000 0101 080a ec11 82ae  .....`..........
    0x0030:  cfeb 55a3 4854 5450 2f31 2e31 2034 3030  ..U.HTTP/1.1.400
    0x0040:  2042 6164 2052 6571 7565 7374 0d0a 636f  .Bad.Request..co
    0x0050:  6e74 656e 742d 7479 7065 3a20 7465 7874  ntent-type:.text
    0x0060:  2f68 746d 6c0d 0a63 6f6e 7465 6e74 2d6c  /html..content-l
    0x0070:  656e 6774 683a 2035 320d 0a0d 0a42 6164  ength:.52....Bad
    0x0080:  2052 6571 7565 7374 2e20 3c62 722f 3e20  .Request..<br/>.
    0x0090:  7465 7874 2069 7320 656d 7074 7920 2870  text.is.empty.(p
    0x00a0:  6f73 7369 626c 7920 4854 5450 2f30 2e39  ossibly.HTTP/0.9
    0x00b0:  29                                       )
kevincai commented 1 day ago

  1. streamload client -> FE:8030, HTTP Header

    PUT /api/tdtest/stream_test/_stream_load HTTP/1.1
Expect: 100-continue
Authorization: Basic cm9vdDo=
label: 39c25a5c-7000-496e-a98e-348a264c81df
Content-Length: 109
Content-Type: text/plain; charset=UTF-8
Host: 127.0.0.1:8030
Connection: Keep-Alive
User-Agent: Apache-HttpClient/4.5.3 (Java/11.0.2)
Accept-Encoding: gzip,deflate

    Be noticed that the http request body is not sent, because there is a Expect: 100-Continue and the client will not send the request body until the server responded 100 Continue or reject the request.

  2. FE server responded a HTTP 307, no 100 Continue included

    HTTP/1.1 307 Temporary Redirect
content-length: 0
location: http://127.0.0.1:8040/api/tdtest/stream_test/_stream_load
content-type: text/html
connection: keep-alive

  3. stream load client sends FE the second request

    PUT /api/tdtest/stream_test/_stream_load HTTP/1.1
Expect: 100-continue
Authorization: Basic cm9vdDo=
label: 39c25a5c-7000-496e-a98e-348a264c81df
Content-Length: 109
Content-Type: text/plain; charset=UTF-8
Host: 127.0.0.1:8030
Connection: Keep-Alive
User-Agent: Apache-HttpClient/4.5.3 (Java/11.0.2)
Accept-Encoding: gzip,deflate

  4. this time FE complains the bad request

    
HTTP/1.1 400 Bad Request
content-type: text/html
content-length: 52

Bad Request.
text is empty (possibly HTTP/0.9)

kevincai commented 1 day ago

While processing the first http request, it says the Content-Length: 109 but not actually send the request body because of the Expect: 100-Continue. And FE doesn't respond 100 Continue to client but just a HTTP 307, so the cient will not send the request body.

Now comes to the second request on the TCP connection, FE tries to discard the previous 109 bytes and then process the new request, and certainly it was a bad request.

kevincai commented 1 day ago

Implementing from RFC7231

A server that responds with a final status code before reading the entire message body SHOULD indicate in that response whether it intends to close the connection or continue reading and discarding the request message (see Section 6.6 of [RFC7230]).

An origin server MUST, upon receiving an HTTP/1.1 (or later) request-line and a complete header section that contains a 100-continue expectation and indicates a request message body will follow, either send an immediate response with a final status code, if that status can be determined by examining just the request-line and header fields, or send an immediate 100 (Continue) response to encourage the client to send the request's message body. The origin server MUST NOT wait for the message body before sending the 100 (Continue) response.

Need to check the java netty framework, how to deal with this 100-Continue behavior properly.

https://netty.io/4.1/api/io/netty/handler/codec/http/HttpObjectAggregator.html