fix: the timer should not be running early.

[tzssangglass]

This PR fixes the error of timer running early.
When calculating steps, discard the part of self.real_time that exceeds the resolution, so that the calculation of steps will not count extra points that have not yet expired.

Fix: FTI-5996

[github-actions]

Luacheck Report

19 tests    1 ✅  0s ⏱️
 1 suites   0 💤
 1 files    18 ❌

For more details on these failures, see this check.

Results for commit 49f14a8.

♻️ This comment has been updated with latest results.

[tzssangglass]

Why does the timer start early?

Timer creation:
The timer is created at real_time: 1722504267.214 with a delay of 5 seconds.
The expected trigger time is 1722504267.214 + 5 = 1722504272.214

When inserting timer:
real_time: 1722504267.214
expected_time: 1722504266.319
delta = 1722504272.132 - 1722504271.319 = 0.813
steps = floor(0.813 / 0.1) = 8
In fact, when within the time range of 1722504267.119(1722504266.319 + 0.800) to 1722504267.218(1722504266.319 + 0.899), the steps are all 8, and the job will be inserted in the slot that the time wheel moves 8 times.

Upon actual triggering:
real_time: 1722504272.132
expected_time: 1722504271.319
The system checked for expired timers
delta = 1722504272.132 - 1722504271.319 = 0.813
steps = floor(0.813 / 0.1) = 8
In fact, when within the time range of 1722504272.119(1722504271.319 + 0.800) to 1722504272.218(1722504271.319 + 0.899), the steps are all 8, and the time wheel will be moved 8 times to check if there are any expired timers in each slot.

When the trigger time is 1722504272.132, the timer that was inserted will be found when the time wheel moves to the 8th slot, even though the expected trigger time of 1722504272.214 has not been reached.

The extreme case is a timer that runs with a delay of 5 seconds inserted at 1722504,267.218, and a timer that can be retrieved at 1722504,272.119, even though the expected trigger time for this timer is 1722504,272.218.

[tzssangglass]

The fix for this PR now is to add 1 step for the once type timer, so that when inserting the timer, it can move one more slot to ensure that the timer will not run early.

[ADD-SP]

Forgot to remove?

[tzssangglass]

yes

[ADD-SP]

Any reason we don't do this for recurrent timers?

[tzssangglass]

If we do this to recurrent timers, they will loop and add +1 step each time they are recreated.

[ADD-SP]

they will loop and add +1 step each time they are recreated.

Sorry, I don't understand. The step is assigned by job.new(...) and will never be changed anymore, I think it should not +1 step for each recreation.

Please let me know if I'm wrong, I haven't touched this codebase for a long time.

[tzssangglass]

yes, you are right, I also think it should not +1 step for each recreation, but I found if apply +1 step for recurrent timers, the trigger time maybe +1 step each time:

2024/08/09 12:01:41 [warn] 1218477#1218477: *4 [lua] 09-jump_the_gun_spec.lua:31: every_func trigger time : 1723176101.188, context: ngx.timer
2024/08/09 12:01:42 [warn] 1218477#1218477: *5 [lua] 09-jump_the_gun_spec.lua:31: every_func trigger time : 1723176102.292, context: ngx.timer
2024/08/09 12:01:43 [warn] 1218477#1218477: *6 [lua] 09-jump_the_gun_spec.lua:31: every_func trigger time : 1723176103.394, context: ngx.timer
2024/08/09 12:01:44 [warn] 1218477#1218477: *7 [lua] 09-jump_the_gun_spec.lua:31: every_func trigger time : 1723176104.496, context: ngx.timer
2024/08/09 12:01:45 [warn] 1218477#1218477: *8 [lua] 09-jump_the_gun_spec.lua:31: every_func trigger time : 1723176105.599, context: ngx.timer
2024/08/09 12:01:46 [warn] 1218477#1218477: *10 [lua] 09-jump_the_gun_spec.lua:31: every_func trigger time : 1723176106.701, context: ngx.timer

reproduce

diff --git a/lib/resty/timerng/job.lua b/lib/resty/timerng/job.lua
index 99e3c65..b4c281d 100644
--- a/lib/resty/timerng/job.lua
+++ b/lib/resty/timerng/job.lua
@@ -241,9 +241,9 @@ function _M.new(wheels, name, callback, delay, once, debug, argc, argv)
         },
     }
 
-    if once then
-        self.steps = self.steps + 1
-    end
+    self.steps = self.steps + 1
+    
+    ngx.log(ngx.WARN, "self.steps : ", require("inspect")(self.steps))
 
     if debug then
         job_create_meta(self)
diff --git a/spec/09-jump_the_gun_spec.lua b/spec/09-jump_the_gun_spec.lua
index 545a2f3..325aaf7 100644
--- a/spec/09-jump_the_gun_spec.lua
+++ b/spec/09-jump_the_gun_spec.lua
@@ -28,17 +28,18 @@ end
 
 local function every_func()
     update_time()
+    ngx.log(ngx.WARN, "every_func trigger time : ", require("inspect")(now()))
 end
 
 local rand_intervals = {
-    0.111,
-    0.222,
-    0.333,
-    0.444,
-    0.555,
-    0.666,
-    0.777,
-    0.888,
+    -- 0.111,
+    -- 0.222,
+    -- 0.333,
+    -- 0.444,
+    -- 0.555,
+    -- 0.666,
+    -- 0.777,
+    -- 0.888,
     0.999,
 }
 
@@ -76,7 +77,7 @@ for rand_interval in pairs(rand_intervals) do
         end)
     
         it("test", function ()
-            local delay = 30 * helper.RESOLUTION
+            local delay = 50 * helper.RESOLUTION
             local interval = 10 * helper.RESOLUTION
             update_time()
     
@@ -96,7 +97,7 @@ for rand_interval in pairs(rand_intervals) do
                 )
             end)
     
-            sleep(4)
+            sleep(6)
     
             local dict = ngx.shared["timer_jump_the_gun"]
             if not dict then

[tzssangglass]

for recurrent timers, if +1 step is added here, such as changing from 10 to 11, then the steps of this recurrent timer will always be 11, and 11 will be obtained each time the pointer is calculated.