Tournament end callback not executed with a reset Schedule

When I create a tournament without a reset schedule and a start and end time, my tournament end callback is executed at the appropriate time (for debugging purposes, I set the end time to +3sec from the start time). However, if I create a tournament with a reset schedule (resetting daily at midnight), a start time and a duration of 3 seconds, but no end time, my tournament end callback is scheduled to execute 3 seconds after the reset time.

My understanding is that the tournament end callback is supposed to execute when the duration from the start time expires, which should be 3 seconds after the start of the tournament in this test case (this seems necessary to reward the winners of the tournament). Why is it scheduling the callback to execute 3 seconds after the reset time instead?

Below are my two test cases. All other code remains the same.

In this following example, the tournament end callback gets executed, but it does not use a reset schedule:

local reset = ""
local duration = 3
local start_time = nakama.time() / 1000
local end_time = start_time + duration
nakama         | {"level":"debug","ts":"2020-11-14T08:10:42.080Z","caller":"server/leaderboard_scheduler.go:265","msg":"Setting timer to run end active function","end_active":"2.9191259s","ids":["4ec4f126-3f9d-11e7-84ef-b7c182b36521"]}
nakama         | {"level":"debug","ts":"2020-11-14T08:10:42.080Z","caller":"server/leaderboard_scheduler.go:271","msg":"Setting timer to run expiry function","expiry":"2.9191259s","ids":["4ec4f126-3f9d-11e7-84ef-b7c182b36521"]}
nakama         | {"level":"info","ts":"2020-11-14T08:10:42.080Z","caller":"server/leaderboard_scheduler.go:278","msg":"Leaderboard scheduler update","end_active":"2.9191259s","end_active_count":1,"expiry":"2.9191259s","expiry_count":1}

And in the next example below, the tournament end callback does not get called within the ~3 seconds. The output says that it is being scheduled 15 hours and change later, which is when the reset is scheduled to occur. The tournament end callback never gets called.

local reset = "0 0 * * *"
local duration = 3
local start_time = nakama.time() / 1000
local end_time = 0
nakama         | {"level":"debug","ts":"2020-11-14T08:06:41.485Z","caller":"server/leaderboard_scheduler.go:265","msg":"Setting timer to run end active function","end_active":"15h53m21.5147s","ids":["4ec4f126-3f9d-11e7-84ef-b7c182b36521"]}
nakama         | {"level":"debug","ts":"2020-11-14T08:06:41.485Z","caller":"server/leaderboard_scheduler.go:271","msg":"Setting timer to run expiry function","expiry":"39h53m18.5147s","ids":["4ec4f126-3f9d-11e7-84ef-b7c182b36521"]}
nakama         | {"level":"info","ts":"2020-11-14T08:06:41.485Z","caller":"server/leaderboard_scheduler.go:278","msg":"Leaderboard scheduler update","end_active":"15h53m21.5147s","end_active_count":1,"expiry":"39h53m18.5147s","expiry_count":1}

I am looking for a solution that allows me to define a reset schedule but also execute the tournament end callback so that I can properly distribute rewards to the winning players. How can I achieve the functionality of the first example while using a reset schedule like in the second example above?

2 Likes

@jamesbaud Good question! When there’s no reset schedule it’s fairly clear I think, so I’ll focus on your example output from the tournament with a reset schedule.

In short what you’re seeing is correct, but not immediately obvious: when a reset schedule is specified that’s the primary factor considered by the scheduler. I’ll use your schedule "0 0 * * *" (once per day, every day, at exactly midnight) and your times/dates as an example.

  1. You create your tournament on 2020-11-14 at 08:06:41, with an immediate start time.
  2. The scheduler checks your reset schedule and determines the next reset will be 2020-11-15 00:00:00, so it works backwards to figure out what the previous reset time was, and therefore what the “current” tournament looks like. That previous reset was 2020-11-14 00:00:00.
  3. Using your duration (3 seconds) your “current” tournament iteration started at 2020-11-14 00:00:00, and has already ended at 2020-11-14 00:00:03 (over 8 hours before the point when you created the tournament). Based on this and your start time it knows that it has missed the entirety of its “current” run. No callbacks are scheduled for the “current” run at all - this is the one ending at 2020-11-15 00:00:00 - because there is no possible way there were any tournament participants this time.
  4. You can see that at 2020-11-14T08:06:41.485Z an end callback is scheduled for 15h53m21.5147s from then, which is 2020-11-15 00:00:03. This is your upcoming reset at next midnight + your duration (3 seconds).
  5. At 2020-11-14T08:06:41.485Z an expiry is also scheduled for 39h53m18.5147s from then. This is 2020-11-16 00:00:00, when records submitted for the 2020-11-15 00:00:00 to 2020-11-15 00:00:03 tournament run are set to expire.

Both your callbacks will execute as expected at the correct times every time, as far as I can tell.

I think the confusion essentially comes in because the tournament is being created after it could have possibly run for that day. The tournament scheduler will defer to the reset schedule. It won’t run a 3-second tournament immediately just because that’s when you’ve created it. If it did you’d have an odd out of place first run at time of creation followed by a run at midnight every day after that.

Worth noting that the start time is still useful even when you have a reset schedule specified. If your start time is in the future the tournament will “skip” runs until the first full run that’s after the start time. Usually you do this to enter tournaments into the future ahead of time and schedule them to begin and become playable at a later date.

Hope this makes sense!

1 Like

@zyro Thanks for that explanation. When looking at it from a big picture perspective, it makes a lot more sense. I misunderstood how the the start time works when it gets paired with a reset schedule.

I do have a follow-up question on the same topic, however. When I register a tournament end callback in both Go and Lua, only the Go callback executes. If I remove the call that registers the tournament end callback in Go, the callback successfully executes in Lua. It appears that one layer has priority over the other. Is this working as intended?

My guess is that only one callback to the tournament end event can be registered at a time. Because the Lua scripts run in a virtual machine within the Go environment, and the Lua scripts run before the Go module is initialized, the callback gets overridden in the Go module. Is this the case?

If I remove the call that registers the tournament end callback in Go, the callback successfully executes in Lua. It appears that one layer has priority over the other. Is this working as intended?

Because the Lua scripts run in a virtual machine within the Go environment, and the Lua scripts run before the Go module is initialized, the callback gets overridden in the Go module. Is this the case?

@jamesbaud This works as expected. The server implements a precedence on the language runtimes it supports. The Go language has precedence over the Lua language. Any server callbacks registered against it will win over the Lua code. This is deterministic by design as it eliminates surprise in development or when deployed to a production environment.