reproduce bug in erlang:now() timer. erl > c(timetest). > timetest:start(150).

timetest.erl

-module(timetest).

-compile(export_all).

-define(DELAY_MS, 100).

start(NumTestProcs) ->
    register(timetest, spawn(?MODULE, timetest, [NumTestProcs]))
    .

timetest(NumTestProcs) ->
    TestProcs = [spawn(?MODULE, timerhammer, [NumTestProcs]) || _ <- lists:seq(1, NumTestProcs)],
    trace(),
    case wait4jump() of
        timejump ->
            [P ! stop || P <- TestProcs],
            Os = ts_to_seconds(os:timestamp()),
            Now = ts_to_seconds(now()),
            io:fwrite("timejump detected!~n"),
            io:fwrite("OS time:    ~b~n", [Os]),
            io:fwrite("now() time: ~b~n", [Now]),
            io:fwrite("now ahead by: ~b seconds~n", [Now - Os]);
        stop ->
            io:fwrite("stopped test~n"),
            [P ! stop || P <- TestProcs]
    end,
    dbg:stop_clear()
    .

stop() ->
    timetest ! stop
    .

trace() ->
    dbg:start(),
    dbg:tracer(port, dbg:trace_port(file, filespec())),
    dbg:p(all, [call, timestamp, 'receive']),
    dbg:tpl(erlang, now, [])
    .

timerhammer(N) ->
    mk_timers(N),
    timer:sleep(?DELAY_MS),
    case wait_timers(N) of
        ok ->
            timer:sleep(1000),
            timerhammer(N);
        O ->
            io:fwrite("exiting...~p~n", [O]),
            O
    end
    .

mk_timers(0) -> [];
mk_timers(N) ->
    erlang:send_after(?DELAY_MS, self(), timeout),
    mk_timers(N-1)
    .

wait_timers(0) ->
    ok;
wait_timers(N) ->
    receive
        stop -> stop;
        timeout -> wait_timers(N-1)
    after
        ?DELAY_MS + 1000 -> no_timer
    end
    .


wait4jump() ->
    OsSeconds = ts_to_seconds(os:timestamp()),
    NowSeconds = ts_to_seconds(now()),
    AbsDiff = abs(NowSeconds - OsSeconds),
    if
        AbsDiff > 1000 ->
            timejump;
        AbsDiff > 5 ->
            io:fwrite("small timejump. now() ahead by ~b seconds ~n", [NowSeconds - OsSeconds]),
            wait4jump();
        true ->
            receive
                stop -> stop
            after
                1000 -> wait4jump()
            end
    end
    .

ts_to_seconds({Mega, Secs, _}) -> (Mega * 1000000) + Secs .

filespec() ->
    {"trace", wrap, ".log", 1024 * 1024 * 10}
    .

gen_tl(TraceOut) ->
    {ok, F} = file:open(TraceOut, write),
    TC = dbg:trace_client(file, filespec(), {fun(Trace,File) ->
                    case Trace of
                        {trace_ts, Pid, Type, MFA, NowTime} ->
                            T = wt(NowTime),
                            file:write(File, io_lib:format("~s|~p  ~p  ~p|~w~n", [T, NowTime, Pid, Type, MFA]));
                        %file:write(File, io_lib:format("~s|~p|~10s--~w~n", [T, Pid, Type, MFA]));
                        {trace_ts, Pid, send, Msg, To, NowTime} ->
                            T = wt(NowTime),
                            file:write(File, io_lib:format("~s|~p  ~p  send(~p)|~w~n", [T, NowTime, Pid, To, Msg]));
                        %file:write(File, io_lib:format("~s|~p|~p ! ~w~n", [T, Pid, To, Msg]));
                        {trace_ts, Pid, spawn, NPid, Initial, NowTime} ->
                            T = wt(NowTime),
                            file:write(File, io_lib:format("~s|~p  ~p  spawn(~p)|~w~n", [T, NowTime, Pid, NPid, Initial]));
                        %file:write(File, io_lib:format("~s|~p|~p -> ~w~n", [T, Pid, NPid, Initial]));
                        Trace -> file:write(File, io_lib:format("~p~n", [Trace]))
                    end,
                    File
            end, F}),
    MR = monitor(process, TC),
    receive {'DOWN', MR, _, _, _} -> ok end,
    file:close(F)
    .

wt({_, _, Usec} = Now) ->
    {{YY, MM, DD}, {H,M,S}} = calendar:now_to_local_time(Now),
    lists:flatten(io_lib:format("~b-~b-~b ~b:~b:~b.~b", [YY, MM, DD, H, M, S, Usec]))
    .