Fix the loop variable scheduler issue

[pmahindrakar-oss]

Tracking issue

#4285

Describe your changes

All kudos to @leonlnj who discovered this bug in Gojek production deployment and helped debug this nasty loop variable issue which caused unnecessary production issue where schedules ran with incorrect times

Overall the issue that was observed was when Gojek redeployed there scheduler, scheduler ran its regular catchup routine to recover from the missed schedule time during the redeploy and found schedules it needed to trigger.
This is well tested behavior in the fleet and we never encountered any issues with it.

But in case of Gojek, it mysteriously ran the schedules which shouldn't have been run and also ran with incorrect catcup from time.

There is much detail in the attached issue.
To summarize,

• The lastExecTime for each active schedule is computed using its updatedAt timestamp and whats stored in the lastsnapshot for that schedule
• If the schedule is available in the snapshot and has timestamp greater than the updatedAt timestamp then we use that timestamp or else we assume schedule was updated recently and hence we should use that for catching up
• Now consider the case where schedules dont have a snapshot and they will all use updatedAt timestamp,
• What was happening though was the lastExecTime which was pointer to loop variable s.UpdatedAt , when the loop variable moved to next schedule, the lastExecTime being pointer used the new schedules UpdatedAt
• So essentially this value will eventually have last schedules UpdatedAt timestamp and in gojek's case it was a new schedule and this schedule's updatedAt timestamp was used as lastExecTime for knowing the catupFromTime for the schedule
• All the active schedules started then firing using the last scheudes updateAt timestamp

The unit test written by Gojek team nicely capture this behavior.
Have updated those tests with assertions and added the loop variable fix.

There is ongoing open golang issue to fix the gotcha which many go developers have complained or ran into golang/go#56010

Hopefully they fix that soon

Check all the applicable boxes

• I updated the documentation accordingly.
• All new and existing tests passed.
• All commits are signed-off.

[pmahindrakar-oss]

cc : @leonlnj

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Comparison is base (db61e22) 58.98% compared to head (c5fa1b4) 76.39%.

Additional details and impacted files

@@             Coverage Diff             @@
##           master    #4468       +/-   ##
===========================================
+ Coverage   58.98%   76.39%   +17.41%     
===========================================
  Files         488       18      -470     
  Lines       41772     1521    -40251     
===========================================
- Hits        24639     1162    -23477     
+ Misses      15172      295    -14877     
+ Partials     1961       64     -1897     

Flag	Coverage Δ
unittests	76.39% <ø> (+17.41%)	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[wild-endeavor]

I'm actually pretty lost... can you help me understand please?

https://goplay.tools/snippet/mNyKXEvyv4q

I understand that the pointer inside the iterator (t here, s in flyte code) doesn't change, cuz it's just one object. But why does that matter? the values that that pointer points to do change.

can you also add a comment where you do schedule := s? feels like something i would just delete if i came across it.

[leonlnj]

I'm actually pretty lost... can you help me understand please?

https://goplay.tools/snippet/mNyKXEvyv4q

I understand that the pointer inside the iterator (t here, s in flyte code) doesn't change, cuz it's just one object. But why does that matter? the values that that pointer points to do change.

can you also add a comment where you do schedule := s? feels like something i would just delete if i came across it.

@wild-endeavor Because the jobStore store the lastExecTime as a pointer, when the iterator move, the value of it changes as well. This cause the catchup function to use an unexpected lastExecTime that don't belong to it and possibly fire schedule that was earlier than the original schedule's updatedAt time. Hope this helps.

https://goplay.tools/snippet/_jD1NzTDZC6

[wild-endeavor]

ohh we're saving it, got it, didn't see that. thank you @leonlnj

[wild-endeavor]

@pmahindrakar-oss could you still remove that weird file? i added a comment.

[pmahindrakar-oss]

@wild-endeavor this might be better example to showcase the issue https://goplay.tools/snippet/J1rE_i5BJxv and have removed the delve debugger file