hackney slow on reading chunked reply of ~20mb #690
Description
Hello,
We've been thinking its Tesla's problem (elixir-tesla/tesla#471) but after profiling we get that reading the large body takes roughly 40 seconds.
Response headers:
<<< RESPONSE <<<
content-lenght:
content-type: application/json
etag: "123-1624560200-ba73c0"
date: Fri, 25 Jun 2021 17:20:10 GMT
transfer-encoding: chunked
profile:
io_lib_fread:fread_skip_white/1 11057 0.00 2178 [ 0.20]
io_lib_fread:fread_result/3 11057 0.00 2182 [ 0.20]
prim_inet:enc_time/1 11057 0.00 2345 [ 0.21]
io_lib_fread:fread/2 11057 0.01 2447 [ 0.22]
hackney_http:read_chunk/2 11056 0.01 2623 [ 0.24]
io_lib_fread:fread1/8 11057 0.01 2632 [ 0.24]
prim_inet:recv/3 11056 0.01 2656 [ 0.24]
hackney_http:'-fun.te_chunked/2-'/2 11057 0.01 2660 [ 0.24]
io_lib_fread:fread_field/3 11057 0.01 3053 [ 0.28]
io_lib_fread:fread_field/1 11057 0.01 3697 [ 0.33]
io_lib:fread/2 11057 0.01 3770 [ 0.34]
erlang:list_to_integer/2 11065 0.01 4087 [ 0.37]
inet_tcp:recv/3 11056 0.01 4200 [ 0.38]
io_lib_fread:fread_field/4 22114 0.01 4220 [ 0.19]
erlang:port_get_data/1 11059 0.01 4906 [ 0.44]
inet_db:lookup_socket/1 11059 0.01 4910 [ 0.44]
lists:reverse/2 22121 0.01 5107 [ 0.23]
hackney_response:stream_body1/2 11057 0.01 5242 [ 0.47]
gen:do_call/4 5 0.01 5411 [ 1082.20]
hackney_tcp:recv/3 11056 0.01 5507 [ 0.50]
prim_inet:ctl_cmd/3 11063 0.01 5975 [ 0.54]
hackney_response:stream_body_recv/2 11055 0.01 5994 [ 0.54]
erlang:port_control/3 11063 0.01 6007 [ 0.54]
hackney_response:recv/1 11056 0.01 6048 [ 0.55]
hackney_response:stream_body/2 11055 0.01 6424 [ 0.58]
io_lib_fread:fread1/7 11057 0.01 6915 [ 0.63]
prim_inet:recv0/3 11056 0.02 7441 [ 0.67]
hackney_response:read_body/3 2 0.02 7485 [ 3742.50]
hackney_http:te_chunked/2 11057 0.02 7831 [ 0.71]
hackney_http:parse_body/1 11058 0.02 7901 [ 0.71]
erlang:send/2 2 0.02 8016 [ 4008.00]
prim_inet:async_recv/3 11056 0.02 8423 [ 0.76]
hackney_http:transfer_decode/2 11057 0.02 8967 [ 0.81]
io_lib_fread:fread/4 22114 0.02 9052 [ 0.41]
hackney_http:read_size/1 11057 0.02 9683 [ 0.88]
gen_tcp:recv/3 11056 0.02 9914 [ 0.90]
lists:reverse/1 33187 0.02 10943 [ 0.33]
io_lib_fread:fread_unsigned/7 11057 0.03 13152 [ 1.19]
io_lib_fread:fread_digits/4 77394 0.03 13471 [ 0.17]
hackney_http:read_size/3 77394 0.26 123753 [ 1.60]
erts_internal:port_control/3 11063 0.27 129846 [ 11.74]
erlang:setelement/3 44314 11.24 5414710 [ 122.19]
hackney_http:execute/2 11067 87.74 42250379 [ 3817.69]
---------------------------------------------- ------ ------- -------- [----------]
Total: 665854 100.00% 48154095 [ 72.32]
"total = 100.02"