benoitc / hackney

simple HTTP client in Erlang
Other
1.34k stars 427 forks source link

Body parsing optimization #710

Closed Polexy closed 1 year ago

Polexy commented 1 year ago

I have found some problem with body parsing for chunked encoded messages: https://github.com/benoitc/hackney/issues/690#issuecomment-1321799256 I have understood parsing logic and optimized it. The main point of it to wait necessary portion of data instead of parsing each packet. My results:

before fix

no chunks:
100 requests, total time: 0.663915s
100 requests, total time: 0.677419s
100 requests, total time: 0.678405s

Total data: 1301.7705078125KB, chunk size: 4096, total chunks: 326
100 requests, total time: 0.742954s
100 requests, total time: 0.727678s
100 requests, total time: 0.709221s

Total data: 1301.7705078125KB, chunk size: 40960, total chunks: 33
100 requests, total time: 0.74006s
100 requests, total time: 0.717082s
100 requests, total time: 0.719162s

Total data: 1301.7705078125KB, chunk size: 409600, total chunks: 4
100 requests, total time: 3.619821s
100 requests, total time: 3.608936s
100 requests, total time: 3.611868s

Total data: 13096.701171875KB, chunk size: 4096000, total chunks: 4
10 requests, total time: 49.382239s

after fix

no chunks:
100 requests, total time: 0.597693s
100 requests, total time: 0.609578s
100 requests, total time: 0.595912s

Total data: 1301.7705078125KB, chunk size: 4096, total chunks: 326
100 requests, total time: 0.694447s
100 requests, total time: 0.690872s
100 requests, total time: 0.668783s

Total data: 1301.7705078125KB, chunk size: 40960, total chunks: 33
100 requests, total time: 0.552928s
100 requests, total time: 0.559099s
100 requests, total time: 0.583001s

Total data: 1301.7705078125KB, chunk size: 409600, total chunks: 4
100 requests, total time: 0.605153s
100 requests, total time: 0.620267s
100 requests, total time: 0.601012s

Total data: 13096.701171875KB, chunk size: 4096000, total chunks: 4
10 requests, total time: 0.604024s

before:

FUNCTION                                      CALLS        %  TIME  [uS / CALLS]
--------                                      -----  -------  ----  [----------]
prim_inet:recv0/3                               1833     0.24     427  [      0.23]
hackney_http:transfer_decode/2                  1838     0.25     444  [      0.24]
hackney_http:te_chunked/2                       1838     0.27     477  [      0.26]
hackney_http:read_size/1                        1838     0.28     499  [      0.27]
prim_inet:async_recv/3                          1833     0.29     514  [      0.28]
hackney_response:read_body/3                       6     0.33     594  [     99.00]
io_lib_fread:fread/4                            3676     0.35     624  [      0.17]
lists:reverse/1                                 5530     0.40     707  [      0.13]
io_lib_fread:fread_unsigned/7                   1838     0.43     762  [      0.41]
io_lib_fread:fread_digits/4                    11938     0.51     900  [      0.08]
erts_internal:port_control/3                    1839     1.49    2655  [      1.44]
hackney_http:read_size/3                       11938     1.86    3317  [      0.28]
erlang:setelement/3                             7421     7.52   13374  [      1.80]
hackney_http:execute/2                          1845    81.92  145728  [     78.99]
--------------------------------------------  ------  -------  ------  [----------]
Total:                                        108568  100.00%  177886  [      1.64]

after:

FUNCTION                                      CALLS        %  TIME  [uS / CALLS]
--------                                      -----  -------  ----  [----------]
erlang:demonitor/2                               29     0.64    33  [      1.14]
io_lib_format:build_limited/5                   144     0.66    34  [      0.24]
erlang:setelement/3                             133     0.85    44  [      0.33]
hackney_bstr:'-to_lower/1-lbc$^0/2-0-'/2        260     1.01    52  [      0.20]
hackney_http:read_size/3                         95     1.03    53  [      0.56]
io_lib_format:collect_cseq/2                     48     1.07    55  [      1.15]
dict:fold_seg/4                                  51     1.14    59  [      1.16]
erts_internal:open_port/2                         1     1.14    59  [     59.00]
io:execute_request/3                             25     1.28    66  [      2.64]
io_lib_format:indentation/2                    1028     1.45    75  [      0.07]
io_lib_format:cdata_to_chars/1                 1028     3.10   160  [      0.16]
erts_internal:port_control/3                     17    14.33   740  [     43.53]
hackney_response:read_body/3                      6    15.67   809  [    134.83]
hackney_http:execute/2                           23    28.20  1456  [     63.30]
--------------------------------------------  -----  -------  ----  [----------]
Total:                                         8996  100.00%  5164  [      0.57]

i have also checked tests\dialyzer on OTP 25.1.1

  All 207 tests passed.
$ ./rebar3 dialyzer
Job succeeded
benoitc commented 1 year ago

thanks!