File download hangs infinitely
I have been using HTTPoison (which uses hackney under the hood) to download hundreds of files per day asynchronously using the stream_to: self() option. I've recently encountered a file that stops receiving after the headers are received. I tried it directly in hackney and get the same result.
The url is http://engine.edocbuilder.com/include/fileDownload.aspx?p=TlP1kM4If79%2fS5yf5VAZfuSSS2SI862sDOM%2fAMvrDvQxjLow6uGW3OoW7aQ1uLPaxlH8MW480DxvjmWU10ihIYZO%2fLkHRzm%2fBbPSXm2FRxPiwxODgyFPPU5Dfdf%2f%2banX&s=26eb1c62-54eb-4800-aae5-eb48b5c8a3c9
Example (In Elixir)
{:ok, 200, headers, ref} = :hackney.get("http://engine.edocbuilder.com/include/fileDownload.aspx?p=TlP1kM4If79%2fS5yf5VAZfuSSS2SI862sDOM%2fAMvrDvQxjLow6uGW3OoW7aQ1uLPaxlH8MW480DxvjmWU10ihIYZO%2fLkHRzm%2fBbPSXm2FRxPiwxODgyFPPU5Dfdf%2f%2banX&s=26eb1c62-54eb-4800-aae5-eb48b5c8a3c9")
{:ok, 200,
[{"Cache-Control", "private"}, {"Transfer-Encoding", "chunked"},
{"Content-Type", "application/pdf"},
{"Expires", "Mon, 24 Apr 2017 19:27:25 GMT"}, {"Server", "Microsoft-IIS/8.5"},
{"Set-Cookie",
"ASP.NET_SessionId=vwk2cd4lv5itarskrcynezym; path=/; HttpOnly"},
{"Content-Disposition", "attachment; filename=production.pdf"},
{"X-Original-Filename-Urlencode", "production.pdf"},
{"X-AspNet-Version", "4.0.30319"}, {"X-Powered-By", "ASP.NET"},
{"X-Webfarm-Member", "eDocProdChi3"}, {"Access-Control-Allow-Origin", "*"},
{"Access-Control-Allow-Headers",
"Content-Type,cache-control,accept,x-requested-with"},
{"Access-Control-Methods", "*"}, {"Date", "Mon, 24 Apr 2017 19:25:25 GMT"}],
#Reference<0.0.3.1945>}
{:ok, body} = :hackney.body(ref)
After the call to :hackney.body(ref) it hangs indefinitely. I have tested and neither httpc or ibrowse have an issue with the url.
what do you mean by "hang"?
The call to {:ok, body} = :hackney.body(ref) doesn't return and cpu spikes.
@jeromedoyle I reproduce the issue.
I thought first that it was an issue with the pathe encoding as curl is sending me a 500 error but it's not the case. I still reproduce it. Tracing the request return the following below. I will have a closer look on it today.
1> hackney_trace:enable(max, io).
ok
2> F = fun(P) -> P end.
#Fun<erl_eval.6.118419387>
3> hackney:get("http://engine.edocbuilder.com/include/fileDownload.aspx?p=TlP1kM4If79%2fS5yf5VAZfuSSS2SI862sDOM%2fAMvrDvQxjLow6uGW3OoW7aQ1uLPaxlH8MW480DxvjmWU10ihIYZO%2fLkHRzm%2fBbPSXm2FRxPiwxODgyFPPU5Dfdf%2f%2banX&s=26eb1c62-54eb-4800-aae5-eb48b5c8a3c9", [], [], [{path_encode, F}, with_body]).
[hackney trace 80 <0.377.0> 2017:05:09 13:54:09 4940] request
Content: [{module,hackney},
{line,308},
{method,get},
{url,{hackney_url,hackney_tcp,http,<<"engine.edocbuilder.com">>,
<<"/include/fileDownload.aspx?p=TlP1kM4If79%2fS5yf5VAZfuSSS2SI862sDOM%2fAMvrDvQxjLow6uGW3OoW7aQ1uLPaxlH8MW480DxvjmWU10ihIYZO%2fLkHRzm%2fBbPSXm2FRxPiwxODgyFPPU5Dfdf%2f%2banX&s=26eb1c62-54eb-4800-aae5-eb48b5c8a3c9">>,
<<"/include/fileDownload.aspx">>,
<<"p=TlP1kM4If79%2fS5yf5VAZfuSSS2SI862sDOM%2fAMvrDvQxjLow6uGW3OoW7aQ1uLPaxlH8MW480DxvjmWU10ihIYZO%2fLkHRzm%2fBbPSXm2FRxPiwxODgyFPPU5Dfdf%2f%2banX&s=26eb1c62-54eb-4800-aae5-eb48b5c8a3c9">>,
<<>>,"engine.edocbuilder.com",80,<<>>,<<>>}},
{headers,[]},
{body,[]},
{options,[{path_encode,#Fun<erl_eval.6.118419387>},with_body]}]
[hackney trace 60 <0.377.0> 2017:05:09 13:54:09 4942] request without proxy
Content: [{module,hackney},{line,680}]
[hackney trace 60 <0.377.0> 2017:05:09 13:54:09 4944] connect
Content: [{module,hackney_connect},
{line,33},
{transport,hackney_tcp},
{host,"engine.edocbuilder.com"},
{port,80},
{dynamic,true}]
[hackney trace 80 <0.377.0> 2017:05:09 13:54:09 4951] no socket in the pool
Content: [{module,hackney_connect},{line,200},{pool,default}]
15:54:09.950 [warning] lager_error_logger_h dropped 83 messages in the last second that exceeded the limit of 50 messages/sec
[hackney trace 80 <0.377.0> 2017:05:09 13:54:10 4153] new connection
Content: [{module,hackney_connect},{line,248}]
[hackney trace 40 <0.377.0> 2017:05:09 13:54:10 4157] perform request
Content: [{module,hackney_request},
{line,100},
{header_data,[<<"GET /include/fileDownload.aspx?p=TlP1kM4If79%2fS5yf5VAZfuSSS2SI862sDOM%2fAMvrDvQxjLow6uGW3OoW7aQ1uLPaxlH8MW480DxvjmWU10ihIYZO%2fLkHRzm%2fBbPSXm2FRxPiwxODgyFPPU5Dfdf%2f%2banX&s=26eb1c62-54eb-4800-aae5-eb48b5c8a3c9 HTTP/1.1\r\n">>,
[[<<"Host">>,": ",<<"engine.edocbuilder.com">>,
"\r\n"],
[<<"User-Agent">>,": ",<<"hackney/1.7.1">>,"\r\n"],
"\r\n"]]},
{perform_all,true},
{expect,false}]
[hackney trace 80 <0.377.0> 2017:05:09 13:54:10 4293] got response
Content: [{module,hackney},
{line,376},
{response,
{ok,200,
[{<<"Cache-Control">>,<<"private">>},
{<<"Transfer-Encoding">>,<<"chunked">>},
{<<"Content-Type">>,<<"application/pdf">>},
{<<"Expires">>,<<"Tue, 09 May 2017 13:56:10 GMT">>},
{<<"Server">>,<<"Microsoft-IIS/8.5">>},
{<<"Set-Cookie">>,
<<"ASP.NET_SessionId=wvqgdyxvqkhe304ahuh21i3g; path=/; HttpOnly">>},
{<<"Content-Disposition">>,
<<"attachment; filename=production.pdf">>},
{<<"X-Original-Filename-Urlencode">>,
<<"production.pdf">>},
{<<"X-AspNet-Version">>,<<"4.0.30319">>},
{<<"X-Powered-By">>,<<"ASP.NET">>},
{<<"X-Webfarm-Member">>,<<"eDocProdChi2">>},
{<<"Access-Control-Allow-Origin">>,<<"*">>},
{<<"Access-Control-Allow-Headers">>,
<<"Content-Type,cache-control,accept,x-requested-with">>},
{<<"Access-Control-Methods">>,<<"*">>},
{<<"Date">>,<<"Tue, 09 May 2017 13:54:10 GMT">>}],
{client,
{1494,338049,943762},
{metrics_ng,metrics_dummy},
hackney_tcp,"engine.edocbuilder.com",80,
<<"engine.edocbuilder.com">>,
[{path_encode,#Fun<erl_eval.6.118419387>},with_body],
#Port<0.84624>,
{default,#Ref<0.0.1.7126>,
{"engine.edocbuilder.com",80,hackney_tcp},
<0.587.0>,hackney_tcp},
#Ref<0.0.1.7126>,true,hackney_pool,5000,false,5,
false,5,nil,nil,
{hparser,response,4096,10,0,on_body,
<<52,100,51,97,48,102,53,13,10,37,80,68,70,45,49,
46,55,13,10,37,249,250,154,231,13,10,49,32,48,
32,111,98,106,13,10,60,60,10,47,65,110,110,111,
116,115,32,55,50,32,48,32,82,10,47,65,114,116,
66,111,120,32,91,50,49,32,50,49,32,49,52,54,49,
32,50,49,48,57,93,10,47,66,108,101,101,100,66,
111,120,32,91,49,50,32,49,50,32,49,52,55,48,32,
50,49,49,56,93,10,47,67,111,110,116,101,110,116,
115,32,91,50,32,48,32,82,32,50,52,32,48,32,82,
93,10,47,67,114,111,112,66,111,120,32,91,48,32,
48,32,49,52,56,50,32,50,49,51,48,93,10,47,77,
101,100,105,97,66,111,120,32,91,48,32,48,32,49,
52,56,50,32,50,49,51,48,93,10,47,80,97,114,101,
110,116,32,52,55,54,32,48,32,82,10,47,82,101,
115,111,117,114,99,101,115,32,60,60,10,47,67,
111,108,111,114,83,112,97,99,101,32,60,60,10,47,
67,83,48,32,52,57,49,32,48,32,82,10,62,62,10,47,
69,120,116,71,83,116,97,116,101,32,60,60,10,47,
71,83,48,32,52,57,50,32,48,32,82,10,47,71,83,49,
32,57,57,32,48,32,82,10,62,62,10,47,70,111,110,
116,32,60,60,10,47,70,97,98,99,49,50,32,49,50,
32,48,32,82,10,47,84,84,48,32,52,57,52,32,48,32,
82,10,62,62,10,47,80,114,111,99,83,101,116,32,
91,47,80,68,70,10,47,84,101,120,116,10,47,73,
109,97,103,101,66,10,47,73,109,97,103,101,67,10,
47,73,109,97,103,101,73,93,10,62,62,10,47,82,
111,116,97,116,101,32,48,10,47,83,116,114,117,
99,116,80,97,114,101,110,116,115,32,49,10,47,84,
114,105,109,66,111,120,32,91,50,49,32,50,49,32,
49,52,54,49,32,50,49,48,57,93,10,47,84,121,112,
101,32,47,80,97,103,101,10,62,62,13,10,101,110,
100,111,98,106,13,10,13,10,50,32,48,32,111,98,
106,13,10,60,60,10,47,76,101,110,103,116,104,32,
55,54,52,10,62,62,13,10,115,116,114,101,97,109,
13,10,113,13,10,48,32,48,32,48,32,49,32,107,10,
47,80,101,114,99,101,112,116,117,97,108,32,114,
105,10,47,71,83,48,32,103,115,10,49,50,32,49,50,
32,49,52,53,56,32,50,49,48,54,32,114,101,10,102,
10,47,83,112,97,110,32,60,60,47,76,97,110,103,
32,40,101,110,45,85,83,41,47,77,67,73,68,32,49,
32,62,62,66,68,67,32,10,66,84,10,48,32,48,32,48,
32,48,32,107,10,47,84,84,48,32,49,32,84,102,10,
55,50,32,48,32,48,32,55,50,32,54,51,52,46,52,56,
48,49,32,49,48,52,50,46,54,56,50,49,32,84,109,
10,40,49,48,48,37,32,75,41,84,106,10,69,84,10,
69,77,67,32,10,57,50,49,32,49,48,53,48,46,52,32,
49,49,56,46,56,32,51,49,46,56,32,114,101,10,102,
10,47,83,112,97,110,32,60,60,47,76,97,110,103,
32,40,101,110,45,85,83,41,47,77,67,73,68,32,50,
32,62,62,66,68,67,32,10,66,84,10,48,32,48,32,48,
32,49,32,107,10,47,71,83,49,32,103,115,10,51,54,
32,48,32,48,32,51,54,32,57,52,51,46,56,56>>,
{1,1},
undefined,[],undefined,<<"chunked">>,undefined,
<<"application/pdf">>,undefined,waiting},
{15,
{dict,15,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],
[[<<"x-webfarm-member">>,
{10,<<"X-Webfarm-Member">>,
<<"eDocProdChi2">>}],
[<<"date">>,
{14,<<"Date">>,
<<"Tue, 09 May 2017 13:54:10 GMT">>}]],
[[<<"expires">>,
{3,<<"Expires">>,
<<"Tue, 09 May 2017 13:56:10 GMT">>}],
[<<"access-control-methods">>,
{13,<<"Access-Control-Methods">>,<<"*">>}]],
[],
[[<<"server">>,
{4,<<"Server">>,<<"Microsoft-IIS/8.5">>}]],
[[<<"content-disposition">>,
{6,<<"Content-Disposition">>,
<<"attachment; filename=production.pdf">>}],
[<<"access-control-allow-origin">>,
{11,<<"Access-Control-Allow-Origin">>,
<<"*">>}]],
[[<<"cache-control">>,
{0,<<"Cache-Control">>,<<"private">>}]],
[],
[[<<"x-powered-by">>,
{9,<<"X-Powered-By">>,<<"ASP.NET">>}],
[<<"access-control-allow-headers">>,
{12,<<"Access-Control-Allow-Headers">>,
<<"Content-Type,cache-control,accept,x-requested-with">>}]],
[[<<"transfer-encoding">>,
{1,<<"Transfer-Encoding">>,<<"chunked">>}],
[<<"content-type">>,
{2,<<"Content-Type">>,
<<"application/pdf">>}]],
[[<<"x-original-filename-urlencode">>,
{7,<<"X-Original-Filename-Urlencode">>,
<<"production.pdf">>}],
[<<"x-aspnet-version">>,
{8,<<"X-AspNet-Version">>,<<"4.0.30319">>}]],
[],
[[<<"set-cookie">>,
{5,<<"Set-Cookie">>,
<<"ASP.NET_SessionId=wvqgdyxvqkhe304ahuh21i3g; path=/; HttpOnly">>}]],
[],[]}}}},
connected,waiting,nil,normal,false,false,true,
undefined,false,#Fun<hackney_request.send.2>,waiting,
nil,4096,<<>>,[],
{1,1},
nil,<<"chunked">>,nil,<<"GET">>,
<<"/include/fileDownload.aspx?p=TlP1kM4If79%2fS5yf5VAZfuSSS2SI862sDOM%2fAMvrDvQxjLow6uGW3OoW7aQ1uLPaxlH8MW480DxvjmWU10ihIYZO%2fLkHRzm%2fBbPSXm2FRxPiwxODgyFPPU5Dfdf%2f%2banX&s=26eb1c62-54eb-4800-aae5-eb48b5c8a3c9">>,
nil}}},
{client,
{client,
{1494,338049,943762},
{metrics_ng,metrics_dummy},
hackney_tcp,"engine.edocbuilder.com",80,
<<"engine.edocbuilder.com">>,
[{path_encode,#Fun<erl_eval.6.118419387>},with_body],
#Port<0.84624>,
{default,#Ref<0.0.1.7126>,
{"engine.edocbuilder.com",80,hackney_tcp},
<0.587.0>,hackney_tcp},
#Ref<0.0.1.7126>,true,hackney_pool,5000,false,5,false,5,
nil,nil,nil,
{0,
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]}}}},
connected,start,nil,normal,false,false,true,undefined,
false,nil,waiting,nil,4096,<<>>,[],undefined,nil,nil,nil,
nil,undefined,nil}}]
Awesome, thank you!
so the error apparently is that it got the full body but wait for the next bit until it timeout (and return the body). Not sure why yet. I will take care over the we.
Awesome, glad you found the issue. Is there anything you need from me?
Any chance this is related to #420?
Any news on this? We are having the same issue :(
I think that I'm facing the same issue. In my case, however, it doesn't hang forever, but takes way to much time to return.
Running the following script takes 384 seconds on my machine, compared to 43 seconds that it takes for wget to download the same 54MB page.
{:ok, 200, _headers, client} = :hackney.request(:get, 'https://github.com/everypolitician/everypolitician-data', [], '', [recv_timeout: 10_000])
start = System.monotonic_time(:second)
{:ok, _body} = :hackney.body(client)
finish = System.monotonic_time(:second)
IO.puts("#{finish - start} seconds")
Elixir: 1.5.1 Erlang: 20 Hackney: 1.9.0
If it's unrelated to the issue please ignore and accept my apologize for interfering.
@Nagasaki45 Not it seems related, thanks for that new link. This chunked encoding definitely needs some love.
I've looked at the trace using hackney_trace and it seems to hang for a while on the first chunk (7665\r\n\n\n\n\n\n\n ...). Not sure why, maybe the size given is not ok, or maybe the time to receive it was too long. Checking.