From a8368cc4aadb172fa7de45fde6e8985446827367 Mon Sep 17 00:00:00 2001 From: Rustem Shaydullin Date: Wed, 15 Jul 2026 15:31:03 +0500 Subject: [PATCH] Fix deadline lenght --- src/woorl.erl | 35 ++++++++++++- test/woorl_timeout_tests.erl | 96 ++++++++++++++++++++++++++++++++++++ 2 files changed, 130 insertions(+), 1 deletion(-) create mode 100644 test/woorl_timeout_tests.erl diff --git a/src/woorl.erl b/src/woorl.erl index 3075433..14dc3a2 100644 --- a/src/woorl.erl +++ b/src/woorl.erl @@ -10,6 +10,10 @@ -export([handle_event/4]). +-ifdef(TEST). +-export([make_transport_opts/1]). +-endif. + %% -define(SUCCESS, 0). @@ -256,7 +260,11 @@ issue_call(Url, Request, Opts) -> ReqID = require_option(reqid, Opts), RpcID = woody_context:new_rpc_id(<<"undefined">>, ReqID, woody_context:new_req_id()), Context = apply_options_to_context(Opts, woody_context:new(RpcID)), - CallOpts = #{url => Url, event_handler => ?MODULE}, + CallOpts = #{ + url => Url, + event_handler => ?MODULE, + transport_opts => make_transport_opts(Context) + }, try woody_client:call(Request, CallOpts, Context) catch @@ -264,6 +272,31 @@ issue_call(Url, Request, Opts) -> {error, Reason} end. +%% By default woody caps connect and send timeouts at 1000ms regardless of the +%% deadline (see woody_client_thrift_http_transport:calc_timeouts/1), so an +%% explicit --deadline would be silently ignored for anything but receiving the +%% response. Let the deadline govern connect and send timeouts as well; woody +%% merges these with application precedence, so recv_timeout still comes from the +%% deadline. +-spec make_transport_opts(woody_context:ctx()) -> woody_client_thrift_http_transport:transport_options(). +make_transport_opts(Context) -> + case woody_context:get_deadline(Context) of + undefined -> + #{}; + Deadline -> + Timeout = deadline_to_timeout(Deadline), + #{connect_timeout => Timeout, send_timeout => Timeout} + end. + +-spec deadline_to_timeout(woody:deadline()) -> non_neg_integer(). +deadline_to_timeout(Deadline) -> + try + woody_deadline:to_timeout(Deadline) + catch + error:deadline_reached -> + 0 + end. + apply_options_to_context(Opts, Context) -> attach_deadline(Opts, attach_user_identity(Opts, Context)). diff --git a/test/woorl_timeout_tests.erl b/test/woorl_timeout_tests.erl new file mode 100644 index 0000000..3679db1 --- /dev/null +++ b/test/woorl_timeout_tests.erl @@ -0,0 +1,96 @@ +-module(woorl_timeout_tests). + +-include_lib("eunit/include/eunit.hrl"). + +-spec test() -> _. + +%% TEST-NET-1 (RFC 5737): guaranteed non-routable, so a TCP connect gets no +%% response and blocks until the connect timeout fires. A faithful stand-in for +%% a service ClusterIP with no healthy backend (SYN silently dropped), which is +%% what the reported `woorl --deadline=1m` call actually hit. +-define(BLACKHOLE_URL, "http://192.0.2.1:8022/v1/test"). + +-spec deadline_timeout_test_() -> _. +deadline_timeout_test_() -> + {setup, + fun() -> + {ok, Apps} = application:ensure_all_started(woorl), + Apps + end, + fun(_Apps) -> ok end, [ + fun parse_yields_full_minute/0, + fun make_transport_opts_no_deadline/0, + fun make_transport_opts_follows_deadline/0, + {timeout, 30, fun default_opts_cap_connect_below_deadline/0}, + {timeout, 30, fun fix_opts_follow_deadline/0} + ]}. + +%% +%% The deadline value is NOT the reason for a sub-second failure: `1m` parses to +%% a full minute. +%% +-spec parse_yields_full_minute() -> _. +parse_yields_full_minute() -> + {ok, Deadline} = woorl_deadline:parse_pretty(<<"1m">>), + Timeout = woody_deadline:to_timeout(Deadline), + ?assert(Timeout > 58000), + ?assert(Timeout =< 60000). + +%% +%% The fix: with a deadline set, connect/send timeouts follow the deadline +%% instead of woody's 1000ms cap; with no deadline nothing is overridden. +%% +-spec make_transport_opts_no_deadline() -> _. +make_transport_opts_no_deadline() -> + ?assertEqual(#{}, woorl:make_transport_opts(woody_context:new())). + +-spec make_transport_opts_follows_deadline() -> _. +make_transport_opts_follows_deadline() -> + Ctx = ctx_with_deadline(<<"1m">>), + #{connect_timeout := Connect, send_timeout := Send} = woorl:make_transport_opts(Ctx), + %% ~60000ms (the full deadline) -- crucially NOT the 1000ms cap + ?assert(Connect > 58000), + ?assert(Send > 58000). + +%% +%% End-to-end reproduction through woody's real transport against a black-hole +%% endpoint, with the SAME 4s deadline in both cases: +%% - default transport opts -> connect capped at 1000ms -> fails at ~1s +%% - the fix's transport opts -> connect follows the deadline -> fails at ~4s +%% This is the direct proof that the sub-second failure was the connect/send cap, +%% not the parsed deadline. +%% +-spec default_opts_cap_connect_below_deadline() -> _. +default_opts_cap_connect_below_deadline() -> + Elapsed = time_flush(ctx_with_deadline(<<"4s">>), #{}), + %% woody caps connect_timeout at 1000ms regardless of the 4s deadline + ?assert(Elapsed > 700), + ?assert(Elapsed < 2500). + +-spec fix_opts_follow_deadline() -> _. +fix_opts_follow_deadline() -> + Ctx = ctx_with_deadline(<<"4s">>), + Elapsed = time_flush(Ctx, woorl:make_transport_opts(Ctx)), + %% connect now runs up to the ~4s deadline instead of the 1s cap + ?assert(Elapsed > 3000), + ?assert(Elapsed < 6000). + +%% +%% helpers +%% + +-spec ctx_with_deadline(binary()) -> woody_context:ctx(). +ctx_with_deadline(Bin) -> + {ok, Deadline} = woorl_deadline:parse_pretty(Bin), + woody_context:set_deadline(Deadline, woody_context:new()). + +-spec time_flush(woody_context:ctx(), map()) -> integer(). +time_flush(Ctx, TransportOpts) -> + WoodyState = woody_state:new(client, Ctx, woody_event_handler_default), + Transport0 = woody_client_thrift_http_transport:new(?BLACKHOLE_URL, TransportOpts, #{}, WoodyState), + {Transport1, ok} = thrift_transport:write(Transport0, <<"ping">>), + Started = erlang:monotonic_time(millisecond), + {_Transport2, Result} = thrift_transport:flush(Transport1), + Elapsed = erlang:monotonic_time(millisecond) - Started, + ?assertMatch({error, _}, Result), + Elapsed.