Ensure creation time is updated on win32 when files are created

src/lager_crash_log.erl

@@ -281,7 +281,7 @@ filesystem_test_() ->
         fun(CrashLog) ->
             {"file can't be opened on startup triggers an error message",
             fun() ->
-                {ok, FInfo} = file:read_file_info(CrashLog),
+                {ok, FInfo} = file:read_file_info(CrashLog, [raw]),
                 file:write_file_info(CrashLog, FInfo#file_info{mode = 0}),
                 {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0, lager_rotator_default),
                 ?assertEqual(1, lager_test_backend:count()),
@@ -301,7 +301,7 @@ filesystem_test_() ->
                 ?assertEqual(1, lager_test_backend:count()),
                 file:delete(CrashLog),
                 file:write_file(CrashLog, ""),
-                {ok, FInfo} = file:read_file_info(CrashLog),
+                {ok, FInfo} = file:read_file_info(CrashLog, [raw]),
                 file:write_file_info(CrashLog, FInfo#file_info{mode = 0}),
                 sync_error_logger:error_msg("Test message\n"),
                 _ = gen_event:which_handlers(error_logger),
@@ -316,7 +316,7 @@ filesystem_test_() ->
         fun(CrashLog) ->
             {"unavailable files that are fixed at runtime should start having log messages written",
             fun() ->
-                {ok, FInfo} = file:read_file_info(CrashLog),
+                {ok, FInfo} = file:read_file_info(CrashLog, [raw]),
                 OldPerms = FInfo#file_info.mode,
                 file:write_file_info(CrashLog, FInfo#file_info{mode = 0}),
                 {ok, _} = ?MODULE:start_link(CrashLog, 65535, 0, undefined, 0, lager_rotator_default),

src/lager_file_backend.erl

@@ -63,8 +63,8 @@
         name :: string(),
         level :: {'mask', integer()},
         fd :: file:io_device() | undefined,
-        inode = undefined :: integer() | undefined,
-        ctime = undefined :: file:date_time() | undefined,
+        inode :: integer() | undefined,
+        ctime :: file:date_time() | undefined,
         flap = false :: boolean(),
         size = 0 :: integer(),
         date :: undefined | string(),
@@ -238,7 +238,6 @@ config_to_id(Config) ->
             {?MODULE, File}
     end.
 
-
 write(#state{name=Name, fd=FD,
              inode=Inode, ctime=Ctime,
              flap=Flap, size=RotSize,
@@ -287,7 +286,7 @@ write_should_check(#state{last_check=LastCheck0, check_interval=CheckInterval,
         true ->
             true;
         _ ->
-            case file:read_file_info(Name) of
+            case file:read_file_info(Name, [raw]) of
                 {ok, #file_info{ctime=Ctime1}} ->
                     Ctime0 =/= Ctime1;
                 _ ->
@@ -564,7 +563,7 @@ rotation_test_() ->
                 end,
 
                 %% although file size is big enough...
-                {ok, FInfo} = file:read_file_info(TestLog),
+                {ok, FInfo} = file:read_file_info(TestLog, [raw]),
                 ?assert(RotationSize < FInfo#file_info.size),
                 %% ...no rotation yet
                 ?assertEqual(PreviousCheck, State2#state.last_check),
@@ -660,9 +659,9 @@ filesystem_test_() ->
         fun() ->
             {ok, TestDir} = lager_util:get_test_dir(),
             TestLog = filename:join(TestDir, "test.log"),
-            ?assertEqual(ok, file:write_file(TestLog, [])),
+            ?assertEqual(ok, safe_write_file(TestLog, [])),
 
-            {ok, FInfo0} = file:read_file_info(TestLog),
+            {ok, FInfo0} = file:read_file_info(TestLog, [raw]),
             FInfo1 = FInfo0#file_info{mode = 0},
             ?assertEqual(ok, file:write_file_info(TestLog, FInfo1)),
 
@@ -691,8 +690,8 @@ filesystem_test_() ->
             lager:log(error, self(), "Test message"),
             ?assertEqual(1, lager_test_backend:count()),
             ?assertEqual(ok, file:delete(TestLog)),
-            ?assertEqual(ok, file:write_file(TestLog, "")),
-            {ok, FInfo0} = file:read_file_info(TestLog),
+            ?assertEqual(ok, safe_write_file(TestLog, "")),
+            {ok, FInfo0} = file:read_file_info(TestLog, [raw]),
             FInfo1 = FInfo0#file_info{mode = 0},
             ?assertEqual(ok, file:write_file_info(TestLog, FInfo1)),
             lager:log(error, self(), "Test message"),
@@ -718,9 +717,9 @@ filesystem_test_() ->
         fun() ->
             {ok, TestDir} = lager_util:get_test_dir(),
             TestLog = filename:join(TestDir, "test.log"),
-            ?assertEqual(ok, file:write_file(TestLog, [])),
+            ?assertEqual(ok, safe_write_file(TestLog, [])),
 
-            {ok, FInfo} = file:read_file_info(TestLog),
+            {ok, FInfo} = file:read_file_info(TestLog, [raw]),
             OldPerms = FInfo#file_info.mode,
             ?assertEqual(ok, file:write_file_info(TestLog, FInfo#file_info{mode = 0})),
             gen_event:add_handler(lager_event, lager_file_backend,
@@ -749,14 +748,16 @@ filesystem_test_() ->
             lager:log(error, self(), "Test message1"),
             ?assertEqual(1, lager_test_backend:count()),
             ?assertEqual(ok, file:delete(TestLog)),
-            ?assertEqual(ok, file:write_file(TestLog, "")),
+            ?assertEqual(ok, safe_write_file(TestLog, "")),
             lager:log(error, self(), "Test message2"),
+            ?assertEqual(2, lager_test_backend:count()),
             {ok, Bin} = file:read_file(TestLog),
             Pid = pid_to_list(self()),
             ?assertMatch([_, _, "[error]", Pid, "Test message2\n"],
                 re:split(Bin, " ", [{return, list}, {parts, 5}])),
             ?assertEqual(ok, file:rename(TestLog, TestLog0)),
             lager:log(error, self(), "Test message3"),
+            ?assertEqual(3, lager_test_backend:count()),
             {ok, Bin2} = file:read_file(TestLog),
             ?assertMatch([_, _, "[error]", Pid, "Test message3\n"],
                 re:split(Bin2, " ", [{return, list}, {parts, 5}]))
@@ -1073,8 +1074,8 @@ formatting_test_() ->
             {ok, TestDir} = lager_util:get_test_dir(),
             Log1 = filename:join(TestDir, "test.log"),
             Log2 = filename:join(TestDir, "test2.log"),
-            ?assertEqual(ok, file:write_file(Log1, [])),
-            ?assertEqual(ok, file:write_file(Log2, [])),
+            ?assertEqual(ok, safe_write_file(Log1, [])),
+            ?assertEqual(ok, safe_write_file(Log2, [])),
             ok = error_logger:tty(false),
             ok = safe_application_load(lager),
             ok = application:set_env(lager, handlers, [{lager_test_backend, info}]),
@@ -1174,4 +1175,11 @@ safe_application_load(App) ->
             ?assertEqual(ok, Error)
     end.
 
+safe_write_file(File, Content) ->
+    ?assertEqual(ok, file:write_file(File, Content)),
+    NewCtime = calendar:local_time(),
+    {ok, FInfo0} = file:read_file_info(File, [raw]),
+    FInfo1 = FInfo0#file_info{ctime = NewCtime},
+    ?assertEqual(ok, file:write_file_info(File, FInfo1, [raw])).
+
 -endif.

src/lager_rotator_default.erl

@@ -26,11 +26,11 @@ open_logfile(Name, Buffer) ->
             end,
             case file:open(Name, Options) of
                 {ok, FD} ->
-                    case file:read_file_info(Name) of
-                        {ok, FInfo} ->
-                            Inode = FInfo#file_info.inode,
-                            Ctime = FInfo#file_info.ctime,
-                            Size1 = FInfo#file_info.size,
+                    case file:read_file_info(Name, [raw]) of
+                        {ok, FInfo0} ->
+                            Inode = FInfo0#file_info.inode,
+                            {ok, Ctime} = maybe_update_ctime(Name, FInfo0),
+                            Size1 = FInfo0#file_info.size,
                             {ok, {FD, Inode, Ctime, Size1}};
                         X -> X
                     end;
@@ -42,7 +42,7 @@ open_logfile(Name, Buffer) ->
 ensure_logfile(Name, undefined, _Inode, _Ctime, Buffer) ->
     open_logfile(Name, Buffer);
 ensure_logfile(Name, FD, Inode0, Ctime0, Buffer) ->
-    case file:read_file_info(Name) of
+    case file:read_file_info(Name, [raw]) of
         {ok, FInfo} ->
             {OsType, _} = os:type(),
             Inode1 = FInfo#file_info.inode,
@@ -83,6 +83,7 @@ rotate_logfile(File, 0) ->
     case file:open(File, [write]) of
         {ok, FD} ->
             _ = file:close(FD),
+            {ok, _Ctime} = maybe_update_ctime(File),
             ok;
         Error ->
             Error
@@ -97,6 +98,29 @@ rotate_logfile(File0, Count) ->
     _ = file:rename(File1, File2),
     rotate_logfile(File0, Count - 1).
 
+maybe_update_ctime(Name) ->
+    case file:read_file_info(Name, [raw]) of
+        {ok, FInfo} ->
+            maybe_update_ctime(Name, FInfo);
+        _ ->
+            {ok, calendar:local_time()}
+    end.
+
+maybe_update_ctime(Name, FInfo) ->
+    {OsType, _} = os:type(),
+    do_update_ctime(OsType, Name, FInfo).
+
+do_update_ctime(win32, Name, FInfo0) ->
+    % Note: we force the creation time to be the current time.
+    % On win32 this may prevent the ctime from being updated:
+    % https://stackoverflow.com/q/8804342/1466825
+    NewCtime = calendar:local_time(),
+    FInfo1 = FInfo0#file_info{ctime = NewCtime},
+    ok = file:write_file_info(Name, FInfo1, [raw]),
+    {ok, NewCtime};
+do_update_ctime(_, _Name, FInfo) ->
+    {ok, FInfo#file_info.ctime}.
+
 -ifdef(TEST).
 
 rotate_file_test() ->
@@ -132,7 +156,7 @@ rotate_file_zero_count_test() ->
     ?assertEqual(true, filelib:is_regular(TestLog)),
     ?assertEqual(1, length(filelib:wildcard(TestLog++"*"))),
     %% assert the new file is 0 size:
-    case file:read_file_info(TestLog) of
+    case file:read_file_info(TestLog, [raw]) of
         {ok, FInfo} ->
             ?assertEqual(0, FInfo#file_info.size);
         _ ->
@@ -171,7 +195,7 @@ rotate_file_fail_test() ->
     ?assertEqual(2, length(filelib:wildcard(TestLog++"*"))),
 
     %% assert the new file is 0 size:
-    case file:read_file_info(TestLog) of
+    case file:read_file_info(TestLog, [raw]) of
         {ok, FInfo} ->
             ?assertEqual(0, FInfo#file_info.size);
         _ ->