Daylight Savings Time Bug

[weixiyen]

Got an argument error :erlang.send_after error in execution_broadcaster.ex during daylight savings time. Seems like the time -576462949368 is very far off during DST.

I'm on v 2.2.3.

22:59:00.055 [error] GenServer XXX.Scheduler.ExecutorSupervisor terminating
** (ArgumentError) argument error
    :erlang.send_after(-576462949368, #PID<0.1335.0>, :execute, [abs: true])
    (quantum) lib/quantum/execution_broadcaster.ex:189: Quantum.ExecutionBroadcaster.reset_timer/1
    (quantum) lib/quantum/execution_broadcaster.ex:87: Quantum.ExecutionBroadcaster.handle_info/2
    (gen_stage) lib/gen_stage.ex:2170: GenStage.noreply_callback/3
    (stdlib) gen_server.erl:616: :gen_server.try_dispatch/4
    (stdlib) gen_server.erl:686: :gen_server.handle_msg/6
    (stdlib) proc_lib.erl:247: :proc_lib.init_p_do_apply/3
Last message: {:DOWN, #Reference<0.508715723.3840147458.49069>, :process, #PID<0.1335.0>, {:badarg, [{:erlang, :send_after, [-576462949368, #PID<0.1335.0>, :execute, [abs: true]], []}, {Quantum.ExecutionBroadcaster, :reset_timer, 1, [file: 'lib/quantum/execution_broadcaster.ex', line: 189]}, {Quantum.ExecutionBroadcaster, :handle_info, 2, [file: 'lib/quantum/execution_broadcaster.ex', line: 87]}, {GenStage, :noreply_callback, 3, [file: 'lib/gen_stage.ex', line: 2170]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 616]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 686]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 247]}]}}
State: %ConsumerSupervisor{args: {XXX.Scheduler.ExecutionBroadcaster, XXX.Scheduler.Task.Supervisor, XXX.Scheduler.TaskRegistry}, children: %{}, max_restarts: 3, max_seconds: 5, mod: Quantum.ExecutorSupervisor, name: XXX.Scheduler.ExecutorSupervisor, producers: %{}, restarting: 0, restarts: [], strategy: :one_for_one, template: {Quantum.Executor, {Quantum.Executor, :start_link, [{XXX.Scheduler.Task.Supervisor, XXX.Scheduler.TaskRegistry}]}, :temporary, 5000, :worker, []}}

[c-rack]

@weixiyen Thanks for reporting. Which timezone have you configured?

[maennchen]

I think that the problem is caused by the line https://github.com/c-rack/quantum-elixir/blob/51f30540a491c8fcdcb221c8d75540894ff6e6cc/lib/quantum/execution_broadcaster.ex#L197

I‘ll work on a fix for the problem tomorrow.

[c-rack]

👍

[maennchen]

I could not yet reproduce the problem. I'll keep you posted.

[weixiyen]

Just to follow up on the timezone question it was "America/New_York"

[maennchen]

I'm able to reproduce the issue now. I need to find the exact cause to find the issue.

If a job in a local timezone jumps over an hour the issue will occur.

The only fix right now is to use UTC in the jobs. I'm going to fix the issue before the DST ends in Europe (on Sunday).

If you have jobs that are running in a TZ in Europe, please follow this issue and update as soon as the fix is out.

[maennchen]

The problem seems to be created in the function ExecutionBroadcaster.add_job_to_state.

Given a job in the timezone Europe/Zurich:

• Executor (UTC) Time is 2018-03-25 00:59:01
• Local Time in Europe/Zurich is 2018-03-25 01:59:01
• crontab calculates the next execution date to be 2018-03-25 02:00:00
  • This time does not exist. It should be 2018-03-25 03:00:00
• UTC Execution Time of that job is 2018-03-25 00:00:00
  • This date is in the past
  • Quantum enters Infinite Loop

[maennchen]

A solution needs to consist of two parts:

1. If ExecutionBroadcaster.add_to_state is given a schedule date in the past, an error should be raised. (To prevent Infinite Loops)
2. Fix dates given by crontab (Crontab only operates with NaiveDateTime)

Does someone have an idea how to solve 2? (Mabye @lau)

This is the function that needs to be patched for 2:

defp add_job_to_state(
       %Job{schedule: schedule, timezone: timezone, name: name} = job,
       %{time: time} = state
     ) do
  schedule
  |> Scheduler.get_next_run_date(DateLibrary.to_tz!(time, timezone))
  |> case do
    {:ok, date} ->
      add_to_state(state, DateLibrary.to_utc!(date, timezone), job)

    _ ->
      Logger.warn("""
      Invalid Schedule #{inspect(schedule)} provided for job #{inspect(name)}.
      No matching dates found. The job was removed.
      """)

      state
  end
rescue
  e in JobInPastError ->
    stacktrace = System.stacktrace()
    reraise(e, stacktrace)

  error ->
    Logger.error(
      "Invalid Timezone #{inspect(timezone)} provided for job #{inspect(name)}.",
      job: job,
      error: error
    )

    state
end

[maennchen]

@weixiyen Would you be willing to try to reproduce the error with the PR #323 ?

[maennchen]

Will be released with #324