gocron: [BUG] - Runs task twice

https://github.com/go-co-op/gocron/issues/132#issuecomment-901945604

Hi, faced the same bug in my environment (MacOS + docker). After some debugging, I found that time.AfterFunc on this line triggers few milliseconds before the expected time. It seems that the root of the problem in golang:

• https://github.com/golang/go/issues/45582
• https://github.com/golang/go/issues/27090

I spent some time digging into golang/go#27090 and TL;DR, there are two calls to the clock_gettime to get monotonic and wall clock times which can cause a slight difference in the two times, more so likely in docker. That being said it sounds like it may not be fixed anytime soon or possibly at all.

My thought then is that rather than relying solely on on time.AfterFunc we put in a check to compare the expected next time.Time the job will be run and if time.AfterFunc returns “early” with regard to the wall clock time, we’ll be able to catch it.

I put together a branch to test this out on. If anyone can test out their code with this branch and see if you still encounter the issue, that would be extremely helpful!

https://github.com/go-co-op/gocron/tree/afterfunc-catch

This has been released with v1.7.1

Using the latest version currently, I encountered a situation where the execution occurs twice. After multiple tests, I found that the occurrence of execution twice is sporadic, and I am not sure under what circumstances it occurs.

Starting server at 0.0.0.0:8881...
{"@timestamp":"2023-10-27T16:43:41.435+08:00","caller":"handler/routes.go:25","content":"--running--","level":"info"}

{"@timestamp":"2023-10-27T16:45:00.000+08:00","caller":"handler/routes.go:25","content":"--running--","level":"info"}
{"@timestamp":"2023-10-27T16:45:00.000+08:00","caller":"handler/routes.go:25","content":"--running--","level":"info"}

{"@timestamp":"2023-10-27T16:48:00.000+08:00","caller":"handler/routes.go:25","content":"--running--","level":"info"}
{"@timestamp":"2023-10-27T16:48:00.000+08:00","caller":"handler/routes.go:25","content":"--running--","level":"info"}

my code:

      s.
	Cron("*/3 * * * *").
	SingletonMode().
	WaitForSchedule().
	Do(func() {
		logx.Info("--running--")
	})

However, when I switched to a lower version for testing, I found that the execution twice situation did not occur.

require(
        //github.com/go-co-op/gocron v1.35.2 // indirect
        github.com/go-co-op/gocron v1.16.3
)

Hi I have same issue with version v1.18, I am scheduling the job 1 time, but it runs twice.

Hi, this fix solves the problem for us! Thanks!

Hello! We had same issue where our task runs twice(e.g. 11:59 and 12:00) in docker(golang:1.16 with MacOS). After testing afterfunc-catch branch, it seems to be fixed! Thank you for your great work, this is very helpful!

@artemgavrilov thanks for digging and finding those issues! I’m going to read up because this is a really interesting bug.

@asmaloney all good! I’ve seen and done that before myself 😞 😂

Hi, reproduced in such a way

cron := "0 0 * * *"
loc, err := time.LoadLocation("Local")
if err != nil {
	err = errors.Wrap(err, funcTitle)
	return
}
sheduler := gocron.NewScheduler(loc)
if _, err = sheduler.Cron(cron).Do(r.SetNextWriter); err != nil {
	err = errors.Wrap(err, funcTitle)
	return
}
sheduler.StartAsync()

Using for log rotation, to log files were created, instead of one.

First 20210426_235959.log

[INFO]: 2021-04-26T23:59:59.955 - See prev log in file logs\20210426_175434.log
[INFO]: 2021-04-27T00:00:00.005 - See next log in file logs\20210427_000000.log

Second 20210427_000000.log

[INFO]: 2021-04-27T00:00:00.005 - See prev log in file logs\20210426_235959.log

Builded and runned on Win10. Using v1.5.0

Case ‘6 0 * * *’ worked correct.

v1.4.0 is released with a fix. Please let us know if you continue to see this issue occurring.

We merged a PR that addressed this. Everything looks good from my tests; If you guys could give it a try and report back the result here, that would be greatly appreciated. If needed, we can reopen this.

@adriendomoison by this weekend or next week for sure! This week I was pretty busy myself but now we’re just finishing up with some month scheduling issues that were happening as well, and we’d be good to go.

Looks to be an issue just with the specific days of the week s1.Every(1).Monday/Tuesday/Wednesday...() . s1.Every(1).Day() works fine, we are using this as a workaround then checking what day it is in the task if anyone else needs this quick 😃

Absolutely, thanks for bringing it out. Will take a look ASAP!

@Streppel could you help me here?