1%%
2%% %CopyrightBegin%
3%%
4%% Copyright Ericsson AB 2017-2020. All Rights Reserved.
5%%
6%% Licensed under the Apache License, Version 2.0 (the "License");
7%% you may not use this file except in compliance with the License.
8%% You may obtain a copy of the License at
9%%
10%%     http://www.apache.org/licenses/LICENSE-2.0
11%%
12%% Unless required by applicable law or agreed to in writing, software
13%% distributed under the License is distributed on an "AS IS" BASIS,
14%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15%% See the License for the specific language governing permissions and
16%% limitations under the License.
17%%
18%% %CopyrightEnd%
19%%
20-module(rabbit_logger_std_h).
21
22%-include("logger.hrl").
23%-include("logger_internal.hrl").
24%-include("logger_h_common.hrl").
25-ifdef(TEST).
26-define(io_put_chars(DEVICE, DATA), begin
27                                        %% We log to Common Test log as well.
28                                        %% This is the file we use to check
29                                        %% the message made it to
30                                        %% stdout/stderr.
31                                        ct:log("~ts", [DATA]),
32                                        io:put_chars(DEVICE, DATA)
33                                    end).
34-else.
35-define(io_put_chars(DEVICE, DATA), io:put_chars(DEVICE, DATA)).
36-endif.
37-define(file_write(DEVICE, DATA), file:write(DEVICE, DATA)).
38-define(file_datasync(DEVICE), file:datasync(DEVICE)).
39
40-include_lib("kernel/include/file.hrl").
41
42%% API
43-export([filesync/1]).
44-export([is_date_based_rotation_needed/3]).
45
46%% logger_h_common callbacks
47-export([init/2, check_config/4, config_changed/3, reset_state/2,
48         filesync/3, write/4, handle_info/3, terminate/3]).
49
50%% logger callbacks
51-export([log/2, adding_handler/1, removing_handler/1, changing_config/3,
52         filter_config/1]).
53
54-define(DEFAULT_CALL_TIMEOUT, 5000).
55
56%%%===================================================================
57%%% API
58%%%===================================================================
59
60%%%-----------------------------------------------------------------
61%%%
62-spec filesync(Name) -> ok | {error,Reason} when
63      Name :: atom(),
64      Reason :: handler_busy | {badarg,term()}.
65
66filesync(Name) ->
67    logger_h_common:filesync(?MODULE,Name).
68
69%%%===================================================================
70%%% logger callbacks - just forward to logger_h_common
71%%%===================================================================
72
73%%%-----------------------------------------------------------------
74%%% Handler being added
75-spec adding_handler(Config) -> {ok,Config} | {error,Reason} when
76      Config :: logger:handler_config(),
77      Reason :: term().
78
79adding_handler(Config) ->
80    logger_h_common:adding_handler(Config).
81
82%%%-----------------------------------------------------------------
83%%% Updating handler config
84-spec changing_config(SetOrUpdate, OldConfig, NewConfig) ->
85                              {ok,Config} | {error,Reason} when
86      SetOrUpdate :: set | update,
87      OldConfig :: logger:handler_config(),
88      NewConfig :: logger:handler_config(),
89      Config :: logger:handler_config(),
90      Reason :: term().
91
92changing_config(SetOrUpdate, OldConfig, NewConfig) ->
93    logger_h_common:changing_config(SetOrUpdate, OldConfig, NewConfig).
94
95%%%-----------------------------------------------------------------
96%%% Handler being removed
97-spec removing_handler(Config) -> ok when
98      Config :: logger:handler_config().
99
100removing_handler(Config) ->
101    logger_h_common:removing_handler(Config).
102
103%%%-----------------------------------------------------------------
104%%% Log a string or report
105-spec log(LogEvent, Config) -> ok when
106      LogEvent :: logger:log_event(),
107      Config :: logger:handler_config().
108
109log(LogEvent, Config) ->
110    logger_h_common:log(LogEvent, Config).
111
112%%%-----------------------------------------------------------------
113%%% Remove internal fields from configuration
114-spec filter_config(Config) -> Config when
115      Config :: logger:handler_config().
116
117filter_config(Config) ->
118    logger_h_common:filter_config(Config).
119
120%%%===================================================================
121%%% logger_h_common callbacks
122%%%===================================================================
123init(Name, Config) ->
124    MyConfig = maps:with([type,file,modes,file_check,max_no_bytes,
125                          rotate_on_date,max_no_files,compress_on_rotate],
126                         Config),
127    case file_ctrl_start(Name, MyConfig) of
128        {ok,FileCtrlPid} ->
129            {ok,MyConfig#{file_ctrl_pid=>FileCtrlPid}};
130        Error ->
131            Error
132    end.
133
134check_config(Name,set,undefined,NewHConfig) ->
135    check_h_config(merge_default_config(Name,normalize_config(NewHConfig)));
136check_config(Name,SetOrUpdate,OldHConfig,NewHConfig0) ->
137    WriteOnce = maps:with([type,file,modes],OldHConfig),
138    Default =
139        case SetOrUpdate of
140            set ->
141                %% Do not reset write-once fields to defaults
142                merge_default_config(Name,WriteOnce);
143            update ->
144                OldHConfig
145        end,
146
147    NewHConfig = maps:merge(Default, normalize_config(NewHConfig0)),
148
149    %% Fail if write-once fields are changed
150    case maps:with([type,file,modes],NewHConfig) of
151        WriteOnce ->
152            check_h_config(NewHConfig);
153        Other ->
154            {error,{illegal_config_change,?MODULE,WriteOnce,Other}}
155    end.
156
157check_h_config(HConfig) ->
158    case check_h_config(maps:get(type,HConfig),maps:to_list(HConfig)) of
159        ok ->
160            {ok,fix_file_opts(HConfig)};
161        {error,{Key,Value}} ->
162            {error,{invalid_config,?MODULE,#{Key=>Value}}}
163    end.
164
165check_h_config(Type,[{type,Type} | Config]) when Type =:= standard_io;
166                                                 Type =:= standard_error;
167                                                 Type =:= file ->
168    check_h_config(Type,Config);
169check_h_config({device,Device},[{type,{device,Device}} | Config]) ->
170    check_h_config({device,Device},Config);
171check_h_config(file,[{file,File} | Config]) when is_list(File) ->
172    check_h_config(file,Config);
173check_h_config(file,[{modes,Modes} | Config]) when is_list(Modes) ->
174    check_h_config(file,Config);
175check_h_config(file,[{max_no_bytes,Size} | Config])
176  when (is_integer(Size) andalso Size>0) orelse Size=:=infinity ->
177    check_h_config(file,Config);
178check_h_config(file,[{rotate_on_date,DateSpec}=Param | Config])
179  when is_list(DateSpec) orelse DateSpec=:=false ->
180    case parse_date_spec(DateSpec) of
181        error -> {error,Param};
182        _ -> check_h_config(file,Config)
183    end;
184check_h_config(file,[{max_no_files,Num} | Config]) when is_integer(Num), Num>=0 ->
185    check_h_config(file,Config);
186check_h_config(file,[{compress_on_rotate,Bool} | Config]) when is_boolean(Bool) ->
187    check_h_config(file,Config);
188check_h_config(file,[{file_check,FileCheck} | Config])
189  when is_integer(FileCheck), FileCheck>=0 ->
190    check_h_config(file,Config);
191check_h_config(_Type,[Other | _]) ->
192    {error,Other};
193check_h_config(_Type,[]) ->
194    ok.
195
196normalize_config(#{type:={file,File}}=HConfig) ->
197    normalize_config(HConfig#{type=>file,file=>File});
198normalize_config(#{type:={file,File,Modes}}=HConfig) ->
199    normalize_config(HConfig#{type=>file,file=>File,modes=>Modes});
200normalize_config(#{file:=File}=HConfig) ->
201    HConfig#{file=>filename:absname(File)};
202normalize_config(HConfig) ->
203    HConfig.
204
205merge_default_config(Name,#{type:=Type}=HConfig) ->
206    merge_default_config(Name,Type,HConfig);
207merge_default_config(Name,#{file:=_}=HConfig) ->
208    merge_default_config(Name,file,HConfig);
209merge_default_config(Name,HConfig) ->
210    merge_default_config(Name,standard_io,HConfig).
211
212merge_default_config(Name,Type,HConfig) ->
213    maps:merge(get_default_config(Name,Type),HConfig).
214
215get_default_config(Name,file) ->
216     #{type => file,
217       file => filename:absname(atom_to_list(Name)),
218       modes => [raw,append],
219       file_check => 0,
220       max_no_bytes => infinity,
221       rotate_on_date => false,
222       max_no_files => 0,
223       compress_on_rotate => false};
224get_default_config(_Name,Type) ->
225     #{type => Type}.
226
227fix_file_opts(#{modes:=Modes}=HConfig) ->
228    HConfig#{modes=>fix_modes(Modes)};
229fix_file_opts(HConfig) ->
230    HConfig#{filesync_repeat_interval=>no_repeat}.
231
232fix_modes(Modes) ->
233    %% Ensure write|append|exclusive
234    Modes1 =
235        case [M || M <- Modes,
236                   lists:member(M,[write,append,exclusive])] of
237            [] -> [append|Modes];
238            _ -> Modes
239        end,
240    %% Ensure raw
241    Modes2 =
242        case lists:member(raw,Modes) of
243            false -> [raw|Modes1];
244            true -> Modes1
245        end,
246    %% Ensure delayed_write
247    case lists:partition(fun(delayed_write) -> true;
248                            ({delayed_write,_,_}) -> true;
249                            (_) -> false
250                         end, Modes2) of
251        {[],_} ->
252            [delayed_write|Modes2];
253        _ ->
254            Modes2
255    end.
256
257config_changed(_Name,
258               #{file_check:=FileCheck,
259                 max_no_bytes:=Size,
260                 rotate_on_date:=DateSpec,
261                 max_no_files:=Count,
262                 compress_on_rotate:=Compress},
263               #{file_check:=FileCheck,
264                 max_no_bytes:=Size,
265                 rotate_on_date:=DateSpec,
266                 max_no_files:=Count,
267                 compress_on_rotate:=Compress}=State) ->
268    State;
269config_changed(_Name,
270               #{file_check:=FileCheck,
271                 max_no_bytes:=Size,
272                 rotate_on_date:=DateSpec,
273                 max_no_files:=Count,
274                 compress_on_rotate:=Compress},
275               #{file_ctrl_pid := FileCtrlPid} = State) ->
276    FileCtrlPid ! {update_config,#{file_check=>FileCheck,
277                                   max_no_bytes=>Size,
278                                   rotate_on_date=>DateSpec,
279                                   max_no_files=>Count,
280                                   compress_on_rotate=>Compress}},
281    State#{file_check:=FileCheck,
282           max_no_bytes:=Size,
283           rotate_on_date:=DateSpec,
284           max_no_files:=Count,
285           compress_on_rotate:=Compress};
286config_changed(_Name,_NewHConfig,State) ->
287    State.
288
289filesync(_Name, SyncAsync, #{file_ctrl_pid := FileCtrlPid} = State) ->
290    Result = file_ctrl_filesync(SyncAsync, FileCtrlPid),
291    {Result,State}.
292
293write(_Name, SyncAsync, Bin, #{file_ctrl_pid:=FileCtrlPid} = State) ->
294    Result = file_write(SyncAsync, FileCtrlPid, Bin),
295    {Result,State}.
296
297reset_state(_Name, State) ->
298    State.
299
300handle_info(_Name, {'EXIT',Pid,Why}, #{file_ctrl_pid := Pid}=State) ->
301    %% file_ctrl_pid died, file error, terminate handler
302    exit({error,{write_failed,maps:with([type,file,modes],State),Why}});
303handle_info(_, _, State) ->
304    State.
305
306terminate(_Name, _Reason, #{file_ctrl_pid:=FWPid}) ->
307    case is_process_alive(FWPid) of
308        true ->
309            unlink(FWPid),
310            _ = file_ctrl_stop(FWPid),
311            MRef = erlang:monitor(process, FWPid),
312            receive
313                {'DOWN',MRef,_,_,_} ->
314                    ok
315            after
316                ?DEFAULT_CALL_TIMEOUT ->
317                    exit(FWPid, kill),
318                    ok
319            end;
320        false ->
321            ok
322    end.
323
324%%%===================================================================
325%%% Internal functions
326%%%===================================================================
327
328%%%-----------------------------------------------------------------
329%%%
330open_log_file(HandlerName,#{type:=file,
331                            file:=FileName,
332                            modes:=Modes,
333                            file_check:=FileCheck}) ->
334    try
335        case filelib:ensure_dir(FileName) of
336            ok ->
337                case file:open(FileName, Modes) of
338                    {ok, Fd} ->
339                        {ok,#file_info{inode=INode}} =
340                            file:read_file_info(FileName,[raw]),
341                        UpdateModes = [append | Modes--[write,append,exclusive]],
342                        {ok,#{handler_name=>HandlerName,
343                              file_name=>FileName,
344                              modes=>UpdateModes,
345                              file_check=>FileCheck,
346                              fd=>Fd,
347                              inode=>INode,
348                              last_check=>timestamp(),
349                              synced=>false,
350                              write_res=>ok,
351                              sync_res=>ok}};
352                    Error ->
353                        Error
354                end;
355            Error ->
356                Error
357        end
358    catch
359        _:Reason -> {error,Reason}
360    end.
361
362close_log_file(#{fd:=Fd}) ->
363    _ = file:datasync(Fd), %% file:datasync may return error as it will flush the delayed_write buffer
364    _ = file:close(Fd),
365    ok;
366close_log_file(_) ->
367    ok.
368
369%% A special close that closes the FD properly when the delayed write close failed
370delayed_write_close(#{fd:=Fd}) ->
371    case file:close(Fd) of
372        %% We got an error while closing, could be a delayed write failing
373        %% So we close again in order to make sure the file is closed.
374        {error, _} ->
375            file:close(Fd);
376        Res ->
377            Res
378    end.
379
380%%%-----------------------------------------------------------------
381%%% File control process
382
383file_ctrl_start(HandlerName, HConfig) ->
384    Starter = self(),
385    FileCtrlPid =
386        spawn_link(fun() ->
387                           file_ctrl_init(HandlerName, HConfig, Starter)
388                   end),
389    receive
390        {FileCtrlPid,ok} ->
391            {ok,FileCtrlPid};
392        {FileCtrlPid,Error} ->
393            Error
394    after
395        ?DEFAULT_CALL_TIMEOUT ->
396            {error,file_ctrl_process_not_started}
397    end.
398
399file_ctrl_stop(Pid) ->
400    Pid ! stop.
401
402file_write(async, Pid, Bin) ->
403    Pid ! {log,Bin},
404    ok;
405file_write(sync, Pid, Bin) ->
406    file_ctrl_call(Pid, {log,Bin}).
407
408file_ctrl_filesync(async, Pid) ->
409    Pid ! filesync,
410    ok;
411file_ctrl_filesync(sync, Pid) ->
412    file_ctrl_call(Pid, filesync).
413
414file_ctrl_call(Pid, Msg) ->
415    MRef = monitor(process, Pid),
416    Pid ! {Msg,{self(),MRef}},
417    receive
418        {MRef,Result} ->
419            demonitor(MRef, [flush]),
420            Result;
421        {'DOWN',MRef,_Type,_Object,Reason} ->
422            {error,Reason}
423    after
424        ?DEFAULT_CALL_TIMEOUT ->
425            %% If this timeout triggers we will get a stray
426            %% reply message in our mailbox eventually.
427            %% That does not really matter though as it will
428            %% end up in this module's handle_info and be ignored
429            demonitor(MRef, [flush]),
430            {error,{no_response,Pid}}
431    end.
432
433file_ctrl_init(HandlerName,
434               #{type:=file,
435                 max_no_bytes:=Size,
436                 rotate_on_date:=DateSpec,
437                 max_no_files:=Count,
438                 compress_on_rotate:=Compress,
439                 file:=FileName} = HConfig,
440               Starter) ->
441    process_flag(message_queue_data, off_heap),
442    case open_log_file(HandlerName,HConfig) of
443        {ok,State} ->
444            Starter ! {self(),ok},
445            %% Do the initial rotate (if any) after we ack the starting
446            %% process as otherwise startup of the system will be
447            %% delayed/crash
448            case parse_date_spec(DateSpec) of
449                error ->
450                    Starter ! {self(),{error,{invalid_date_spec,DateSpec}}};
451                ParsedDS ->
452                    RotState = update_rotation({Size,ParsedDS,Count,Compress},State),
453                    file_ctrl_loop(RotState)
454            end;
455        {error,Reason} ->
456            Starter ! {self(),{error,{open_failed,FileName,Reason}}}
457    end;
458file_ctrl_init(HandlerName, #{type:={device,Dev}}, Starter) ->
459    Starter ! {self(),ok},
460    file_ctrl_loop(#{handler_name=>HandlerName,dev=>Dev});
461file_ctrl_init(HandlerName, #{type:=StdDev}, Starter) ->
462    Starter ! {self(),ok},
463    file_ctrl_loop(#{handler_name=>HandlerName,dev=>StdDev}).
464
465file_ctrl_loop(State) ->
466    receive
467        %% asynchronous event
468        {log,Bin} ->
469            State1 = write_to_dev(Bin,State),
470            file_ctrl_loop(State1);
471
472        %% synchronous event
473        {{log,Bin},{From,MRef}} ->
474            State1 = ensure_file(State),
475            State2 = write_to_dev(Bin,State1),
476            From ! {MRef,ok},
477            file_ctrl_loop(State2);
478
479        filesync ->
480            State1 = sync_dev(State),
481            file_ctrl_loop(State1);
482
483        {filesync,{From,MRef}} ->
484            State1 = ensure_file(State),
485            State2 = sync_dev(State1),
486            From ! {MRef,ok},
487            file_ctrl_loop(State2);
488
489        {update_config,#{file_check:=FileCheck,
490                         max_no_bytes:=Size,
491                         rotate_on_date:=DateSpec,
492                         max_no_files:=Count,
493                         compress_on_rotate:=Compress}} ->
494            case parse_date_spec(DateSpec) of
495                error ->
496                    %% FIXME: Report parsing error?
497                    file_ctrl_loop(State#{file_check=>FileCheck});
498                ParsedDS ->
499                    State1 = update_rotation({Size,ParsedDS,Count,Compress},State),
500                    file_ctrl_loop(State1#{file_check=>FileCheck})
501            end;
502
503        stop ->
504            close_log_file(State),
505            stopped
506    end.
507
508maybe_ensure_file(#{file_check:=0}=State) ->
509    ensure_file(State);
510maybe_ensure_file(#{last_check:=T0,file_check:=CheckInt}=State)
511  when is_integer(CheckInt) ->
512    T = timestamp(),
513    if T-T0 > CheckInt -> ensure_file(State);
514       true -> State
515    end;
516maybe_ensure_file(State) ->
517    State.
518
519%% In order to play well with tools like logrotate, we need to be able
520%% to re-create the file if it has disappeared (e.g. if rotated by
521%% logrotate)
522ensure_file(#{inode:=INode0,file_name:=FileName,modes:=Modes}=State) ->
523    case file:read_file_info(FileName,[raw]) of
524        {ok,#file_info{inode=INode0}} ->
525            State#{last_check=>timestamp()};
526        _ ->
527            close_log_file(State),
528            case file:open(FileName,Modes) of
529                {ok,Fd} ->
530                    {ok,#file_info{inode=INode}} =
531                        file:read_file_info(FileName,[raw]),
532                    State#{fd=>Fd,inode=>INode,
533                           last_check=>timestamp(),
534                           synced=>true,sync_res=>ok};
535                Error ->
536                    exit({could_not_reopen_file,Error})
537            end
538    end;
539ensure_file(State) ->
540    State.
541
542write_to_dev(Bin,#{dev:=DevName}=State) ->
543    ?io_put_chars(DevName, Bin),
544    State;
545write_to_dev(Bin, State) ->
546    State1 = #{fd:=Fd} = maybe_ensure_file(State),
547    Result = ?file_write(Fd, Bin),
548    State2 = maybe_rotate_file(Bin,State1),
549    maybe_notify_error(write,Result,State2),
550    State2#{synced=>false,write_res=>Result}.
551
552sync_dev(#{synced:=false}=State) ->
553    State1 = #{fd:=Fd} = maybe_ensure_file(State),
554    Result = ?file_datasync(Fd),
555    maybe_notify_error(filesync,Result,State1),
556    State1#{synced=>true,sync_res=>Result};
557sync_dev(State) ->
558    State.
559
560update_rotation({infinity,false,_,_},State) ->
561    maybe_remove_archives(0,State),
562    maps:remove(rotation,State);
563update_rotation({Size,DateSpec,Count,Compress},#{file_name:=FileName}=State) ->
564    maybe_remove_archives(Count,State),
565    {ok,#file_info{size=CurrSize}} = file:read_file_info(FileName,[raw]),
566    State1 = State#{rotation=>#{size=>Size,
567                                on_date=>DateSpec,
568                                count=>Count,
569                                compress=>Compress,
570                                curr_size=>CurrSize}},
571    maybe_update_compress(0,State1),
572    maybe_rotate_file(0,State1).
573
574parse_date_spec(false) ->
575    false;
576parse_date_spec("") ->
577    false;
578parse_date_spec([$$,$D | DateSpec]) ->
579    io:format(standard_error, "parse_date_spec: ~p (hour)~n", [DateSpec]),
580    parse_hour(DateSpec, #{every=>day,
581                           hour=>0});
582parse_date_spec([$$,$W | DateSpec]) ->
583    io:format(standard_error, "parse_date_spec: ~p (week)~n", [DateSpec]),
584    parse_day_of_week(DateSpec, #{every=>week,
585                                  hour=>0});
586parse_date_spec([$$,$M | DateSpec]) ->
587    io:format(standard_error, "parse_date_spec: ~p (month)~n", [DateSpec]),
588    parse_day_of_month(DateSpec, #{every=>month,
589                                   hour=>0});
590parse_date_spec(DateSpec) ->
591    io:format(standard_error, "parse_date_spec: ~p (error)~n", [DateSpec]),
592    error.
593
594parse_hour(Rest,Result) ->
595    case date_string_to_int(Rest,0,23) of
596        {Hour,""} -> Result#{hour=>Hour};
597        error -> error
598    end.
599
600parse_day_of_week(Rest,Result) ->
601    case date_string_to_int(Rest,0,6) of
602        {DayOfWeek,Rest} -> parse_hour(Rest,Result#{day_of_week=>DayOfWeek});
603        error -> error
604    end.
605
606parse_day_of_month([Last | Rest],Result)
607  when Last=:=$l orelse Last=:=$L ->
608    parse_hour(Rest,Result#{day_of_month=>last});
609parse_day_of_month(Rest,Result) ->
610    case date_string_to_int(Rest,1,31) of
611        {DayOfMonth,Rest} -> parse_hour(Rest,Result#{day_of_month=>DayOfMonth});
612        error -> error
613    end.
614
615date_string_to_int(String,Min,Max) ->
616    case string:to_integer(String) of
617        {Int,Rest} when is_integer(Int) andalso Int>=Min andalso Int=<Max ->
618            {Int,Rest};
619        _ ->
620            error
621    end.
622
623maybe_remove_archives(Count,#{file_name:=FileName}=State) ->
624    Archive = rot_file_name(FileName,Count,false),
625    CompressedArchive = rot_file_name(FileName,Count,true),
626    case {file:read_file_info(Archive,[raw]),
627          file:read_file_info(CompressedArchive,[raw])} of
628        {{error,enoent},{error,enoent}} ->
629            ok;
630        _ ->
631            _ = file:delete(Archive),
632            _ = file:delete(CompressedArchive),
633            maybe_remove_archives(Count+1,State)
634    end.
635
636maybe_update_compress(Count,#{rotation:=#{count:=Count}}) ->
637    ok;
638maybe_update_compress(N,#{file_name:=FileName,
639                          rotation:=#{compress:=Compress}}=State) ->
640    Archive = rot_file_name(FileName,N,not Compress),
641    case file:read_file_info(Archive,[raw]) of
642        {ok,_} when Compress ->
643            compress_file(Archive);
644        {ok,_} ->
645            decompress_file(Archive);
646        _ ->
647            ok
648    end,
649    maybe_update_compress(N+1,State).
650
651maybe_rotate_file(Bin,#{rotation:=_}=State) when is_binary(Bin) ->
652    maybe_rotate_file(byte_size(Bin),State);
653maybe_rotate_file(AddSize,#{rotation:=#{size:=RotSize,
654                                        curr_size:=CurrSize}=Rotation}=State) ->
655    {DateBasedRotNeeded, Rotation1} = is_date_based_rotation_needed(Rotation),
656    NewSize = CurrSize + AddSize,
657    if NewSize>RotSize ->
658            rotate_file(State#{rotation=>Rotation1#{curr_size=>NewSize}});
659       DateBasedRotNeeded ->
660            rotate_file(State#{rotation=>Rotation1#{curr_size=>NewSize}});
661       true ->
662            State#{rotation=>Rotation1#{curr_size=>NewSize}}
663    end;
664maybe_rotate_file(_Bin,State) ->
665    State.
666
667is_date_based_rotation_needed(#{last_rotation_ts:=PrevTimestamp,
668                                on_date:=DateSpec}=Rotation) ->
669    CurrTimestamp = rotation_timestamp(),
670    case is_date_based_rotation_needed(DateSpec,PrevTimestamp,CurrTimestamp) of
671        true -> {true,Rotation#{last_rotation_ts=>CurrTimestamp}};
672        false -> {false,Rotation}
673    end;
674is_date_based_rotation_needed(Rotation) ->
675    {false,Rotation#{last_rotation_ts=>rotation_timestamp()}}.
676
677is_date_based_rotation_needed(#{every:=day,hour:=Hour},
678                              {Date1,Time1},{Date2,Time2})
679  when (Date1<Date2 orelse (Date1=:=Date2 andalso Time1<{Hour,0,0})) andalso
680       Time2>={Hour,0,0} ->
681    true;
682is_date_based_rotation_needed(#{every:=day,hour:=Hour},
683                              {Date1,_}=DateTime1,{Date2,Time2}=DateTime2)
684  when Date1<Date2 andalso
685       Time2<{Hour,0,0} ->
686    GregDays2 = calendar:date_to_gregorian_days(Date2),
687    TargetDate = calendar:gregorian_days_to_date(GregDays2 - 1),
688    TargetDateTime = {TargetDate,{Hour,0,0}},
689    DateTime1<TargetDateTime andalso DateTime2>=TargetDateTime;
690is_date_based_rotation_needed(#{every:=week,day_of_week:=TargetDoW,hour:=Hour},
691                              DateTime1,{Date2,_}=DateTime2) ->
692    DoW2 = calendar:day_of_the_week(Date2) rem 7,
693    DaysSinceTargetDoW = ((DoW2 - TargetDoW) + 7) rem 7,
694    GregDays2 = calendar:date_to_gregorian_days(Date2),
695    TargetGregDays = GregDays2 - DaysSinceTargetDoW,
696    TargetDate = calendar:gregorian_days_to_date(TargetGregDays),
697    TargetDateTime = {TargetDate,{Hour,0,0}},
698    DateTime1<TargetDateTime andalso DateTime2>=TargetDateTime;
699is_date_based_rotation_needed(#{every:=month,day_of_month:=last,hour:=Hour},
700                              DateTime1,{{Year2,Month2,_}=Date2,_}=DateTime2) ->
701    DoMA = calendar:last_day_of_the_month(Year2, Month2),
702    DateA = {Year2,Month2,DoMA},
703    TargetDate = if
704                     DateA>Date2 ->
705                         case Month2 - 1 of
706                             0 ->
707                                 {Year2-1,12,31};
708                             MonthB ->
709                                 {Year2,MonthB,
710                                  calendar:last_day_of_the_month(Year2,MonthB)}
711                         end;
712                     true ->
713                         DateA
714                 end,
715    TargetDateTime = {TargetDate,{Hour,0,0}},
716    io:format(standard_error, "TargetDateTime=~p~n", [TargetDateTime]),
717    DateTime1<TargetDateTime andalso DateTime2>=TargetDateTime;
718is_date_based_rotation_needed(#{every:=month,day_of_month:=DoM,hour:=Hour},
719                              DateTime1,{{Year2,Month2,_}=Date2,_}=DateTime2) ->
720    DateA = {Year2,Month2,adapt_day_of_month(Year2,Month2,DoM)},
721    TargetDate = if
722                     DateA>Date2 ->
723                         case Month2 - 1 of
724                             0 ->
725                                 {Year2-1,12,31};
726                             MonthB ->
727                                 {Year2,MonthB,
728                                  adapt_day_of_month(Year2,MonthB,DoM)}
729                         end;
730                     true ->
731                         DateA
732                 end,
733    TargetDateTime = {TargetDate,{Hour,0,0}},
734    io:format(standard_error, "TargetDateTime=~p~n", [TargetDateTime]),
735    DateTime1<TargetDateTime andalso DateTime2>=TargetDateTime;
736is_date_based_rotation_needed(_,_,_) ->
737    false.
738
739adapt_day_of_month(Year,Month,Day) ->
740    LastDay = calendar:last_day_of_the_month(Year,Month),
741    erlang:min(Day,LastDay).
742
743rotate_file(#{file_name:=FileName,modes:=Modes,rotation:=Rotation}=State) ->
744    State1 = sync_dev(State),
745    _ = delayed_write_close(State),
746    rotate_files(FileName,maps:get(count,Rotation),maps:get(compress,Rotation)),
747    case file:open(FileName,Modes) of
748        {ok,Fd} ->
749            {ok,#file_info{inode=INode}} = file:read_file_info(FileName,[raw]),
750            CurrTimestamp = rotation_timestamp(),
751            State1#{fd=>Fd,inode=>INode,
752                    rotation=>Rotation#{curr_size=>0,
753                                        last_rotation_ts=>CurrTimestamp}};
754        Error ->
755            exit({could_not_reopen_file,Error})
756    end.
757
758rotation_timestamp() ->
759    calendar:now_to_local_time(erlang:timestamp()).
760
761rotate_files(FileName,0,_Compress) ->
762    _ = file:delete(FileName),
763    ok;
764rotate_files(FileName,1,Compress) ->
765    FileName0 = FileName++".0",
766    _ = file:rename(FileName,FileName0),
767    if Compress -> compress_file(FileName0);
768       true -> ok
769    end,
770    ok;
771rotate_files(FileName,Count,Compress) ->
772    _ = file:rename(rot_file_name(FileName,Count-2,Compress),
773                    rot_file_name(FileName,Count-1,Compress)),
774    rotate_files(FileName,Count-1,Compress).
775
776rot_file_name(FileName,Count,false) ->
777    FileName ++ "." ++ integer_to_list(Count);
778rot_file_name(FileName,Count,true) ->
779    rot_file_name(FileName,Count,false) ++ ".gz".
780
781compress_file(FileName) ->
782    {ok,In} = file:open(FileName,[read,binary]),
783    {ok,Out} = file:open(FileName++".gz",[write]),
784    Z = zlib:open(),
785    zlib:deflateInit(Z, default, deflated, 31, 8, default),
786    compress_data(Z,In,Out),
787    zlib:deflateEnd(Z),
788    zlib:close(Z),
789    _ = file:close(In),
790    _ = file:close(Out),
791    _ = file:delete(FileName),
792    ok.
793
794compress_data(Z,In,Out) ->
795    case file:read(In,100000) of
796        {ok,Data} ->
797            Compressed = zlib:deflate(Z, Data),
798            _ = file:write(Out,Compressed),
799            compress_data(Z,In,Out);
800        eof ->
801            Compressed = zlib:deflate(Z, <<>>, finish),
802            _ = file:write(Out,Compressed),
803            ok
804    end.
805
806decompress_file(FileName) ->
807    {ok,In} = file:open(FileName,[read,binary]),
808    {ok,Out} = file:open(filename:rootname(FileName,".gz"),[write]),
809    Z = zlib:open(),
810    zlib:inflateInit(Z, 31),
811    decompress_data(Z,In,Out),
812    zlib:inflateEnd(Z),
813    zlib:close(Z),
814    _ = file:close(In),
815    _ = file:close(Out),
816    _ = file:delete(FileName),
817    ok.
818
819decompress_data(Z,In,Out) ->
820    case file:read(In,1000) of
821        {ok,Data} ->
822            Decompressed = zlib:inflate(Z, Data),
823            _ = file:write(Out,Decompressed),
824            decompress_data(Z,In,Out);
825        eof ->
826            ok
827    end.
828
829maybe_notify_error(_Op, ok, _State) ->
830    ok;
831maybe_notify_error(Op, Result, #{write_res:=WR,sync_res:=SR})
832  when (Op==write andalso Result==WR) orelse
833       (Op==filesync andalso Result==SR) ->
834    %% don't report same error twice
835    ok;
836maybe_notify_error(Op, Error, #{handler_name:=HandlerName,file_name:=FileName}) ->
837    logger_h_common:error_notify({HandlerName,Op,FileName,Error}),
838    ok.
839
840timestamp() ->
841    erlang:monotonic_time(millisecond).
842