erlang httpc request timeout 問題.

概述

線上發現http client偶有很是長的超時. 因而深挖一下erlang httpc 的超時.

httpc request 耗時

一個http請求耗時包含以下部分

• 建立連接(若沒有可用的連接)
• 發送/等待返回

在erlang httpc中由以下兩個參數控制:
timeout
Time-out time for the request.
The clock starts ticking when the request is sent.
Time is in milliseconds.
Default is infinity.

connect_timeout
Connection time-out time, used during the initial request, when the client is connecting to the server.
Time is in milliseconds.
Default is the value of option timeout.

測試與驗證

connect_timeout

首先修改iptables, 將80口的包drop掉.

iptables -A INPUT -p tcp --dport 80 -j DROP

在elixir控制檯執行以下, 發現默認的超時時間是130s.

fun_a = fn ->
    require Logger
    start_time = :erlang.system_time(:second)
    reply = :httpc.request('http://localhost')
    Logger.info("reply:#{inspect reply}")
    end_time = :erlang.system_time(:second)
    end_time - start_time
end
fun_a.()
[11:12:01.394] [info] file=iex line=17  reply:{:error, {:failed_connect, [{:to_address, {'localhost', 80}}, {:inet, [:inet], :timeout}]}}
130

connect_timeout 參數

:httpc.request(:get, {'http://localhost', []}, [{:connect_timeout, 5000}], [])

調用如上, 超時變爲5S.

timeout

先還原防火牆設置.

Chain INPUT (policy ACCEPT)
target     prot opt source               destination         
DROP       tcp  --  anywhere             anywhere             tcp dpt:http

Chain FORWARD (policy DROP)
target     prot opt source               destination 
iptables -D INPUT 1

建立flask http hello world server

~/code_repo/python/flask_hello(master*) » cat hello.py
from flask import Flask
app = Flask(__name__)

@app.route('/')
def hello_world():
   return 'Hello, World!'

~/code_repo/python/flask_hello(master*) » export FLASK_APP=hello.py
~/code_repo/python/flask_hello(master*) » python3 -m flask run
 * Serving Flask app "hello.py"
 * Environment: production
   WARNING: This is a development server. Do not use it in a production deployment.
   Use a production WSGI server instead.
 * Debug mode: off
 * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
127.0.0.1 - - [04/Jul/2020 11:33:59] "GET / HTTP/1.1" 200 -
127.0.0.1 - - [04/Jul/2020 11:34:03] "GET / HTTP/1.1" 200 -
127.0.0.1 - - [04/Jul/2020 11:34:04] "GET / HTTP/1.1" 200 -

驗證

iex(19)> :httpc.request('http://localhost:5000')
{:ok,
 {{'HTTP/1.0', 200, 'OK'},
  [
    {'date', 'Sat, 04 Jul 2020 03:34:04 GMT'},
    {'server', 'Werkzeug/1.0.1 Python/3.8.2'},
    {'content-length', '13'},
    {'content-type', 'text/html; charset=utf-8'}
  ], 'Hello, World!'}}

在return hello world以前, sleep 9999s. 等待了10分鐘也未能返回.

:httpc.request('http://localhost:5000')

傳入timeout後, 會有timeout錯誤.

iex(5)> :httpc.request(:get, {'http://localhost:5000', []}, [{:timeout, 5000}], [])
{:error, :timeout}

實現

erlang版本:
OTP-21.3.8.9

connect_timeout

能夠看到，connect_timeout做爲參數傳入ssl的connect
http_transport.erl:104

connect({ssl, SslConfig}, Address, Opts, Timeout) ->
    connect({?HTTP_DEFAULT_SSL_KIND, SslConfig}, Address, Opts, Timeout);

connect({essl, SslConfig}, {Host, Port}, Opts0, Timeout) -> 
    Opts = [binary, {active, false}, {ssl_imp, new} | Opts0] ++ SslConfig,
    case (catch ssl:connect(Host, Port, Opts, Timeout)) of
    {'EXIT', Reason} ->
        {error, {eoptions, Reason}};
    {ok, _} = OK ->
        OK;
    {error, _} = ERROR ->
        ERROR
    end.

ssl的默認transport就是gen_tcp，因此，http/https在設置connect_timeout時，都是經過gen_tcp的timeout實現的．更多細節參考
erlang gen_tcp connect

timeout

timeout的實現是send以後立刻註冊一個timer.
httpc_handler.erl:1250

activate_request_timeout(
  #state{request = #request{timer = OldRef} = Request} = State) ->
    Timeout = (Request#request.settings)#http_options.timeout,
    case Timeout of
    infinity ->
        State;
    _ ->
        ReqId = Request#request.id, 
        Msg       = {timeout, ReqId}, 
        case OldRef of
        undefined ->
            ok;
        _ ->
            %% Timer is already running! This is the case for a redirect or retry
            %% We need to restart the timer because the handler pid has changed
            cancel_timer(OldRef, Msg)
        end,
        Ref       = erlang:send_after(Timeout, self(), Msg), 
        Request2  = Request#request{timer = Ref}, 
        ReqTimers = [{Request#request.id, Ref} |
             (State#state.timers)#timers.request_timers],
        Timers    = #timers{request_timers = ReqTimers}, 
        State#state{request = Request2, timers = Timers}
    end.

activate_queue_timeout(infinity, State) ->
    State;
activate_queue_timeout(Time, State) ->
    Ref = erlang:send_after(Time, self(), timeout_queue),
    State#state{timers = #timers{queue_timer = Ref}}.

以後經過send消息返回調用者. 最終返回 {:error, :timeout} 錯誤.

httpc_response:send(Request#request.from, 
                        httpc_response:error(Request, timeout)),

總結

使用erlang httpc 要記得設置兩個timeout. 讓超時時間可控.