Sign Up
Log In
Log In
or
Sign Up
Places
All Projects
Status Monitor
Collapse sidebar
home:Ledest:erlang:23
erlang
0940-logger-Fix-repeated-filesync-shutdown-time...
Overview
Repositories
Revisions
Requests
Users
Attributes
Meta
File 0940-logger-Fix-repeated-filesync-shutdown-timeout.patch of Package erlang
From 3bb17665ea77e1b549ae3f3da2c9189f019620ad Mon Sep 17 00:00:00 2001 From: Lukas Larsson <lukas@erlang.org> Date: Mon, 28 Mar 2022 11:02:07 +0200 Subject: [PATCH] logger: Fix repeated filesync shutdown timeout The commit 06cacbc (aka PR #4811) changed where the timer_server is located in the supervisor tree of Kernel. This change caused the timer_server to be terminated before logger, which meant that the calls to timer:cancel from any logger backend would timeout. We solve this by instead using erlang:start_timer for the repeated filesync timer. Closes #5780 --- lib/kernel/src/logger_h_common.erl | 58 ++++++++++++--------- lib/kernel/test/logger_disk_log_h_SUITE.erl | 11 ++-- lib/kernel/test/logger_std_h_SUITE.erl | 9 ++-- 3 files changed, 47 insertions(+), 31 deletions(-) diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl index bbd45ac73d..f0db587af1 100644 --- a/lib/kernel/src/logger_h_common.erl +++ b/lib/kernel/src/logger_h_common.erl @@ -260,17 +260,39 @@ handle_call(filesync, _From, State = #{id := Name, {Result,HandlerState1} = Module:filesync(Name,sync,HandlerState), {reply, Result, State#{handler_state=>HandlerState1, last_op=>sync}}. +handle_cast({config_changed, CommonConfig, HConfig}, + State = #{id := Name, + module := Module, + handler_state := HandlerState, + filesync_repeat_interval := OldFSyncInt}) -> + State1 = + case maps:get(filesync_repeat_interval,CommonConfig) of + OldFSyncInt -> + State; + FSyncInt -> + set_repeated_filesync( + cancel_repeated_filesync( + State#{filesync_repeat_interval=>FSyncInt})) + end, + HS = try Module:config_changed(Name, HConfig, HandlerState) + catch error:undef -> HandlerState + end, + {noreply, State1#{handler_state => HS}}. + %% If FILESYNC_REPEAT_INTERVAL is set to a millisec value, this %% clause gets called repeatedly by the handler. In order to %% guarantee that a filesync *always* happens after the last log %% event, the repeat operation must be active! -handle_cast(repeated_filesync,State = #{filesync_repeat_interval := no_repeat}) -> +handle_info({timeout, TRef, repeated_filesync}, + State = #{rep_sync_tref := TRef, + filesync_repeat_interval := no_repeat}) -> %% This clause handles a race condition which may occur when %% config changes filesync_repeat_interval from an integer value %% to no_repeat. {noreply,State}; -handle_cast(repeated_filesync, +handle_info({timeout, TRef, repeated_filesync}, State = #{id := Name, + rep_sync_tref := TRef, module := Module, handler_state := HandlerState, last_op := LastOp}) -> @@ -282,25 +304,6 @@ handle_cast(repeated_filesync, State#{handler_state => HS, last_op => sync} end, {noreply,set_repeated_filesync(State1)}; -handle_cast({config_changed, CommonConfig, HConfig}, - State = #{id := Name, - module := Module, - handler_state := HandlerState, - filesync_repeat_interval := OldFSyncInt}) -> - State1 = - case maps:get(filesync_repeat_interval,CommonConfig) of - OldFSyncInt -> - State; - FSyncInt -> - set_repeated_filesync( - cancel_repeated_filesync( - State#{filesync_repeat_interval=>FSyncInt})) - end, - HS = try Module:config_changed(Name, HConfig, HandlerState) - catch error:undef -> HandlerState - end, - {noreply, State1#{handler_state => HS}}. - handle_info(Info, #{id := Name, module := Module, handler_state := HandlerState} = State) -> {noreply,State#{handler_state => Module:handle_info(Name,Info,HandlerState)}}. @@ -445,8 +448,7 @@ get_default_config() -> set_repeated_filesync(#{filesync_repeat_interval:=FSyncInt} = State) when is_integer(FSyncInt) -> - {ok,TRef} = timer:apply_after(FSyncInt, gen_server, cast, - [self(),repeated_filesync]), + TRef = erlang:start_timer(FSyncInt, self(), repeated_filesync), State#{rep_sync_tref=>TRef}; set_repeated_filesync(State) -> State. @@ -454,7 +456,15 @@ set_repeated_filesync(State) -> cancel_repeated_filesync(State) -> case maps:take(rep_sync_tref,State) of {TRef,State1} -> - _ = timer:cancel(TRef), + case erlang:cancel_timer(TRef) of + false -> + %% Flush the timer message + receive + {timeout, TRef, _} -> ok + end; + _ -> + ok + end, State1; error -> State diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index a4e4e52309..2c7a43faa7 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -656,10 +656,10 @@ sync(Config) -> %% switch repeated filesync on and verify that the looping works SyncInt = 1000, WaitT = 4500, - OneSync = {logger_h_common,handle_cast,repeated_filesync}, + OneSync = {logger_h_common,handle_info,{timeout,repeated_filesync}}, %% receive 1 repeated_filesync per sec - start_tracer([{{logger_h_common,handle_cast,2}, - [{[repeated_filesync,'_'],[],[{message,{caller}}]}]}], + start_tracer([{{logger_h_common,handle_info,2}, + [{[{timeout,'_',repeated_filesync},'_'],[],[{message,{caller}}]}]}], [OneSync || _ <- lists:seq(1, trunc(WaitT/SyncInt))]), HConfig2 = HConfig#{filesync_repeat_interval => SyncInt}, @@ -1610,13 +1610,16 @@ tpl([{{M,F,A},MS}|Trace]) -> tpl([]) -> ok. -tracer({trace,_,call,{logger_h_common,handle_cast,[Op|_]},Caller}, +tracer({trace,_,call,{logger_h_common = Mod,handle_cast = Func,[Op|_]},Caller}, {Pid,[{Mod,Func,Op}|Expected]}) -> maybe_tracer_done(Pid,Expected,{Mod,Func,Op},Caller); tracer({trace,_,call,{Mod=logger_disk_log_h,Func=disk_log_write,[_,_,Data]},Caller}, {Pid,[{Mod,Func,Data}|Expected]}) -> maybe_tracer_done(Pid,Expected,{Mod,Func,Data},Caller); tracer({trace,_,call,{Mod,Func,_},Caller}, {Pid,[{Mod,Func}|Expected]}) -> maybe_tracer_done(Pid,Expected,{Mod,Func},Caller); +tracer({trace,_,call,{logger_h_common = Mod,handle_info = Func,[{timeout,_,Op},_S]},Caller}, + {Pid,[{Mod,Func,{timeout,Op}}|Expected]}) -> + maybe_tracer_done(Pid,Expected,{Mod,Func},Caller); tracer({trace,_,call,Call,Caller}, {Pid,Expected}) -> ct:log("Tracer got unexpected: ~p~nCaller: ~p~nExpected: ~p~n",[Call,Caller,Expected]), Pid ! {tracer_got_unexpected,Call,Expected}, diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index 08962eec0f..33310e8fad 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -817,10 +817,10 @@ sync(Config) -> %% switch repeated filesync on and verify that the looping works SyncInt = 1000, WaitT = 4500, - OneSync = {logger_h_common,handle_cast,repeated_filesync}, + OneSync = {logger_h_common,handle_info,{timeout,repeated_filesync}}, %% receive 1 repeated_filesync per sec - start_tracer([{{logger_h_common,handle_cast,2}, - [{[repeated_filesync,'_'],[],[]}]}], + start_tracer([{{logger_h_common,handle_info,2}, + [{[{timeout,'_',repeated_filesync},'_'],[],[]}]}], [OneSync || _ <- lists:seq(1, trunc(WaitT/SyncInt))]), ok = logger:update_handler_config(?MODULE, config, @@ -2182,6 +2182,9 @@ tracer({trace,_,call,{Mod=logger_std_h,Func=write_to_dev,[Data,_]}}, maybe_tracer_done(Pid,Expected,{Mod,Func,Data}); tracer({trace,_,call,{Mod,Func,_}}, {Pid,[{Mod,Func}|Expected]}) -> maybe_tracer_done(Pid,Expected,{Mod,Func}); +tracer({trace,_,call,{logger_h_common = Mod,handle_info = Func,[{timeout,_,Op},_S]}}, + {Pid,[{Mod,Func,{timeout,Op}}|Expected]}) -> + maybe_tracer_done(Pid,Expected,{Mod,Func}); tracer({trace,_,call,Call}, {Pid,Expected}) -> ct:log("Tracer got unexpected: ~p~nExpected: ~p~n",[Call,Expected]), Pid ! {tracer_got_unexpected,Call,Expected}, -- 2.34.1
Locations
Projects
Search
Status Monitor
Help
OpenBuildService.org
Documentation
API Documentation
Code of Conduct
Contact
Support
@OBShq
Terms
openSUSE Build Service is sponsored by
The Open Build Service is an
openSUSE project
.
Sign Up
Log In
Places
Places
All Projects
Status Monitor
