From 5a33fda25f34c0d7446ea14e561643ddd0ebe351 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lo=C3=AFc=20Hoguin?= Date: Fri, 27 Mar 2020 13:37:18 +0100 Subject: Improve test timeout handling in gun_SUITE Instead of timeouts, favor receiving events from the event handler gun_test_event_h. Remove most other timeouts in particular receive timeouts in favor of a Common Test timetrap timeout global to this test suite of 30 seconds. --- test/gun_SUITE.erl | 288 ++++++++++++++++++++++++---------------------- test/gun_test_event_h.erl | 65 +++++++++++ 2 files changed, 215 insertions(+), 138 deletions(-) create mode 100644 test/gun_test_event_h.erl diff --git a/test/gun_SUITE.erl b/test/gun_SUITE.erl index 0667cac..ca8dab5 100644 --- a/test/gun_SUITE.erl +++ b/test/gun_SUITE.erl @@ -22,18 +22,17 @@ -import(gun_test, [init_origin/3]). -import(gun_test, [receive_from/1]). -import(gun_test, [receive_all_from/2]). +-import(gun_test_event_h, [receive_event/1]). +-import(gun_test_event_h, [receive_event/2]). + +suite() -> + [{timetrap, 30000}]. all() -> [{group, gun}]. groups() -> - %% On Windows we sometimes have timeout related failures due to - %% some operations taking longer. Best retry a few times. - Props = case os:type() of - {win32, _} -> [{repeat_until_all_ok, 10}]; - _ -> [] - end, - [{gun, [parallel|Props], ct_helper:all(?MODULE)}]. + [{gun, [parallel], ct_helper:all(?MODULE)}]. %% Tests. @@ -80,17 +79,17 @@ domain_lookup_timeout_infinity(_) -> do_timeout(domain_lookup_timeout, infinity). do_timeout(Opt, Timeout) -> - {ok, Pid} = gun:open("localhost", 12345, #{Opt => Timeout, retry => 0}), - Ref = monitor(process, Pid), - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - ok - after 2000 -> - %% This is not an error, the timeout was accepted but - %% the connect or domain lookup is just taking too long, - %% for example when it was set to infinity. - gun:close(Pid) - end. + {ok, ConnPid} = gun:open("localhost", 12345, #{ + Opt => Timeout, + event_handler => {gun_test_event_h, self()}, + retry => 0 + }), + %% The connection will not succeed. We will however receive + %% an init event from the connection process that indicates + %% that the timeout value was accepted, since the timeout + %% checks occur earlier. + {_, init, _} = receive_event(ConnPid), + gun:close(ConnPid). ignore_empty_data_http(_) -> doc("When gun:data/4 is called with nofin and empty data, it must be ignored."), @@ -140,17 +139,18 @@ info(_) -> keepalive_infinity(_) -> doc("Ensure infinity for keepalive is accepted by all protocols."), - {ok, Pid} = gun:open("localhost", 12345, #{ + {ok, ConnPid} = gun:open("localhost", 12345, #{ + event_handler => {gun_test_event_h, self()}, http_opts => #{keepalive => infinity}, http2_opts => #{keepalive => infinity}, - retry => 0}), - Ref = monitor(process, Pid), - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - ok - after 5000 -> - error(timeout) - end. + retry => 0 + }), + %% The connection will not succeed. We will however receive + %% an init event from the connection process that indicates + %% that the timeout value was accepted, since the timeout + %% checks occur earlier. + {_, init, _} = receive_event(ConnPid), + gun:close(ConnPid). killed_streams_http(_) -> doc("Ensure completed responses with a connection: close are not considered killed streams."), @@ -174,8 +174,6 @@ killed_streams_http(_) -> {gun_down, ConnPid, http, normal, KilledStreams} -> [] = KilledStreams, gun:close(ConnPid) - after 1000 -> - error(timeout) end. list_header_name(_) -> @@ -209,22 +207,22 @@ map_headers(_) -> postpone_request_while_not_connected(_) -> doc("Ensure Gun doesn't raise error when requesting in retries"), %% Try connecting to a server that isn't up yet. - {ok, Pid} = gun:open("localhost", 23456, #{retry => 5, retry_timeout => 1000}), - _ = gun:get(Pid, "/postponed"), - %% Make sure the connect call completed and we are waiting for a retry. - Timeout = case os:type() of - {win32, _} -> 2500; - _ -> 500 - end, - timer:sleep(Timeout), + {ok, ConnPid} = gun:open("localhost", 23456, #{ + event_handler => {gun_test_event_h, self()}, + retry => 5, + retry_timeout => 1000 + }), + _ = gun:get(ConnPid, "/postponed"), + %% Wait for the connection attempt. to fail. + {_, connect_end, #{error := _}} = receive_event(ConnPid, connect_end), %% Start the server so that next retry will result in the client connecting successfully. {ok, ListenSocket} = gen_tcp:listen(23456, [binary, {active, false}, {reuseaddr, true}]), {ok, ClientSocket} = gen_tcp:accept(ListenSocket, 5000), %% The client should now be up. - {ok, http} = gun:await_up(Pid), + {ok, http} = gun:await_up(ConnPid), %% The server receives the postponed request. {ok, <<"GET /postponed HTTP/1.1\r\n", _/bits>>} = gen_tcp:recv(ClientSocket, 0, 5000), - ok. + gun:close(ConnPid). reply_to(_) -> doc("The reply_to option allows using a separate process for requests."), @@ -251,8 +249,6 @@ do_reply_to(Protocol) -> receive Ref -> Response = gun:await(Pid, Ref), Self ! Response - after 1000 -> - error(timeout) end end), Ref = gun:get(Pid, "/", [], #{reply_to => ReplyTo}), @@ -287,146 +283,164 @@ do_reply_to(Protocol) -> receive {response, _, _, _} -> gun:close(Pid) - after 1000 -> - error(timeout) end. retry_0(_) -> doc("Ensure Gun gives up immediately with retry=0."), - {ok, Pid} = gun:open("localhost", 12345, #{retry => 0, retry_timeout => 500}), - Ref = monitor(process, Pid), - %% On Windows when the connection is refused the OS will retry - %% a few times before giving up, with a delay between tries. - %% This adds time to connection failures. - After = case os:type() of - {win32, _} -> 2300; - _ -> 300 - end, - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - ok - after After -> - error(timeout) - end. + {ok, ConnPid} = gun:open("localhost", 12345, #{ + event_handler => {gun_test_event_h, self()}, + retry => 0, + retry_timeout => 500 + }), + {_, init, _} = receive_event(ConnPid), + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _}} = receive_event(ConnPid), + {_, terminate, _} = receive_event(ConnPid), + ok. retry_0_disconnect(_) -> doc("Ensure Gun gives up immediately with retry=0 after a successful connection."), {ok, ListenSocket} = gen_tcp:listen(0, [binary, {active, false}]), {ok, {_, Port}} = inet:sockname(ListenSocket), - {ok, Pid} = gun:open("localhost", Port, #{retry => 0, retry_timeout => 500}), - Ref = monitor(process, Pid), - %% On Windows when the connection is refused the OS will retry - %% a few times before giving up, with a delay between tries. - %% This adds time to connection failures. - After = case os:type() of - {win32, _} -> 2300; - _ -> 300 - end, + {ok, ConnPid} = gun:open("localhost", Port, #{ + event_handler => {gun_test_event_h, self()}, + retry => 0, + retry_timeout => 500 + }), + {_, init, _} = receive_event(ConnPid), + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), %% We accept the connection and then close it to trigger a disconnect. {ok, ClientSocket} = gen_tcp:accept(ListenSocket, 5000), gen_tcp:close(ClientSocket), - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - ok - after After -> - error(timeout) - end. + %% Connection was successful. + {_, connect_end, ConnectEndEvent} = receive_event(ConnPid), + false = maps:is_key(error, ConnectEndEvent), + %% When the connection is closed we terminate immediately. + {_, disconnect, _} = receive_event(ConnPid), + {_, terminate, _} = receive_event(ConnPid), + ok. retry_1(_) -> doc("Ensure Gun gives up with retry=1."), - {ok, Pid} = gun:open("localhost", 12345, #{retry => 1, retry_timeout => 500}), - Ref = monitor(process, Pid), - After = case os:type() of - {win32, _} -> 4800; - _ -> 800 - end, - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - ok - after After -> - error(timeout) - end. + {ok, ConnPid} = gun:open("localhost", 12345, #{ + event_handler => {gun_test_event_h, self()}, + retry => 1, + retry_timeout => 500 + }), + {_, init, _} = receive_event(ConnPid), + %% Initial attempt. + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _}} = receive_event(ConnPid), + %% Retry. + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _}} = receive_event(ConnPid), + {_, terminate, _} = receive_event(ConnPid), + ok. retry_1_disconnect(_) -> - doc("Ensure Gun gives up with retry=1 after a successful connection."), + doc("Ensure Gun doesn't give up with retry=1 after a successful connection " + "and attempts to reconnect immediately, ignoring retry_timeout."), {ok, ListenSocket} = gen_tcp:listen(0, [binary, {active, false}]), {ok, {_, Port}} = inet:sockname(ListenSocket), - {ok, Pid} = gun:open("localhost", Port, #{retry => 1, retry_timeout => 500}), + {ok, ConnPid} = gun:open("localhost", Port, #{ + event_handler => {gun_test_event_h, self()}, + retry => 1, + retry_timeout => 30000 + }), + {_, init, _} = receive_event(ConnPid), + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), %% We accept the connection and then close it to trigger a disconnect. {ok, ClientSocket} = gen_tcp:accept(ListenSocket, 5000), gen_tcp:close(ClientSocket), - %% We confirm that Gun reconnects immediately. - {ok, _} = gen_tcp:accept(ListenSocket, 200), - gun:close(Pid). + %% Connection was successful. + {_, connect_end, ConnectEndEvent} = receive_event(ConnPid), + false = maps:is_key(error, ConnectEndEvent), + %% We confirm that Gun reconnects before the retry timeout, + %% as it is ignored on the first reconnection. + {ok, _} = gen_tcp:accept(ListenSocket, 5000), + gun:close(ConnPid). retry_fun(_) -> doc("Ensure the retry_fun is used when provided."), - {ok, Pid} = gun:open("localhost", 12345, #{ + {ok, ConnPid} = gun:open("localhost", 12345, #{ + event_handler => {gun_test_event_h, self()}, retry => 5, - retry_fun => fun(_, _) -> #{retries => 0, timeout => 500} end, - retry_timeout => 5000 + retry_fun => fun(_, _) -> #{retries => 0, timeout => 0} end, + retry_timeout => 60000 }), - Ref = monitor(process, Pid), - After = case os:type() of - {win32, _} -> 4800; - _ -> 800 - end, - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - ok - after After -> - error(shutdown_too_late) - end. + {_, init, _} = receive_event(ConnPid), + %% Initial attempt. + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _}} = receive_event(ConnPid), + %% When retry is not disabled (retry!=0) we necessarily + %% have at least one retry attempt using the fun. + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _}} = receive_event(ConnPid), + {_, terminate, _} = receive_event(ConnPid), + ok. retry_timeout(_) -> doc("Ensure the retry_timeout value is enforced. The first retry is immediate " "and therefore does not use the timeout."), - {ok, Pid} = gun:open("localhost", 12345, #{retry => 2, retry_timeout => 1000}), - Ref = monitor(process, Pid), - After = case os:type() of - {win32, _} -> 4800; - _ -> 800 - end, - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - error(shutdown_too_early) - after After -> - ok - end, - receive - {'DOWN', Ref, process, Pid, {shutdown, _}} -> - ok - after After -> - error(shutdown_too_late) - end. + {ok, ConnPid} = gun:open("localhost", 12345, #{ + event_handler => {gun_test_event_h, self()}, + retry => 2, + retry_timeout => 1000 + }), + {_, init, _} = receive_event(ConnPid), + %% Initial attempt. + {_, domain_lookup_start, _} = receive_event(ConnPid), + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _, ts := TS1}} = receive_event(ConnPid), + %% First retry is immediate. + {_, domain_lookup_start, #{ts := TS2}} = receive_event(ConnPid), + true = (TS2 - TS1) < 1000, + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _, ts := TS3}} = receive_event(ConnPid), + %% Second retry occurs after the retry_timeout. + {_, domain_lookup_start, #{ts := TS4}} = receive_event(ConnPid), + true = (TS4 - TS3) >= 1000, + {_, domain_lookup_end, _} = receive_event(ConnPid), + {_, connect_start, _} = receive_event(ConnPid), + {_, connect_end, #{error := _}} = receive_event(ConnPid), + {_, terminate, _} = receive_event(ConnPid), + ok. set_owner(_) -> doc("The owner of the connection can be changed."), Self = self(), - Pid = spawn(fun() -> + spawn(fun() -> {ok, ConnPid} = gun:open("localhost", 12345), gun:set_owner(ConnPid, Self), Self ! {conn, ConnPid} end), - Ref = monitor(process, Pid), - receive {'DOWN', Ref, process, Pid, _} -> ok after 1000 -> error(timeout) end, - ConnPid = receive {conn, C} -> C after 1000 -> error(timeout) end, + ConnPid = receive {conn, C} -> C end, #{owner := Self} = gun:info(ConnPid), gun:close(ConnPid). shutdown_reason(_) -> doc("The last connection failure must be propagated."), - {ok, Pid} = gun:open("localhost", 12345, #{retry => 0}), - Ref = monitor(process, Pid), - After = case os:type() of - {win32, _} -> 2300; - _ -> 300 - end, + {ok, ConnPid} = gun:open("localhost", 12345, #{retry => 0}), + Ref = monitor(process, ConnPid), receive - {'DOWN', Ref, process, Pid, {shutdown, econnrefused}} -> - ok - after After -> - error(timeout) + {'DOWN', Ref, process, ConnPid, {shutdown, econnrefused}} -> + gun:close(ConnPid) end. stream_info_http(_) -> @@ -561,8 +575,6 @@ do_unix_socket_connect() -> receive {recv, _} -> gun:close(Pid) - after 250 -> - error(timeout) end. uppercase_header_name(_) -> diff --git a/test/gun_test_event_h.erl b/test/gun_test_event_h.erl new file mode 100644 index 0000000..98b2669 --- /dev/null +++ b/test/gun_test_event_h.erl @@ -0,0 +1,65 @@ +%% Copyright (c) 2020, Loïc Hoguin +%% +%% Permission to use, copy, modify, and/or distribute this software for any +%% purpose with or without fee is hereby granted, provided that the above +%% copyright notice and this permission notice appear in all copies. +%% +%% THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES +%% WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF +%% MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR +%% ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES +%% WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN +%% ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF +%% OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE. + +-module(gun_test_event_h). +-compile(export_all). +-compile(nowarn_export_all). + +init(Event, State) -> common(?FUNCTION_NAME, Event, State). +domain_lookup_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +domain_lookup_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +connect_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +connect_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +tls_handshake_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +tls_handshake_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +request_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +request_headers(Event, State) -> common(?FUNCTION_NAME, Event, State). +request_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +push_promise_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +push_promise_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +response_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +response_inform(Event, State) -> common(?FUNCTION_NAME, Event, State). +response_headers(Event, State) -> common(?FUNCTION_NAME, Event, State). +response_trailers(Event, State) -> common(?FUNCTION_NAME, Event, State). +response_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +ws_upgrade(Event, State) -> common(?FUNCTION_NAME, Event, State). +ws_recv_frame_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +ws_recv_frame_header(Event, State) -> common(?FUNCTION_NAME, Event, State). +ws_recv_frame_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +ws_send_frame_start(Event, State) -> common(?FUNCTION_NAME, Event, State). +ws_send_frame_end(Event, State) -> common(?FUNCTION_NAME, Event, State). +protocol_changed(Event, State) -> common(?FUNCTION_NAME, Event, State). +transport_changed(Event, State) -> common(?FUNCTION_NAME, Event, State). +origin_changed(Event, State) -> common(?FUNCTION_NAME, Event, State). +cancel(Event, State) -> common(?FUNCTION_NAME, Event, State). +disconnect(Event, State) -> common(?FUNCTION_NAME, Event, State). +terminate(Event, State) -> common(?FUNCTION_NAME, Event, State). + +common(EventType, Event, State=Pid) -> + Pid ! {self(), EventType, Event#{ + ts => erlang:system_time(millisecond) + }}, + State. + +receive_event(Pid) -> + receive + Msg = {Pid, EventType, Event} when is_atom(EventType), is_map(Event) -> + Msg + end. + +receive_event(Pid, EventType) -> + receive + Msg = {Pid, EventType, Event} when is_map(Event) -> + Msg + end. -- cgit v1.2.3