Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

A small bug when using c.AddFunc after c.Start #34

Closed
qiukeren opened this issue Nov 23, 2015 · 13 comments
Closed

A small bug when using c.AddFunc after c.Start #34

qiukeren opened this issue Nov 23, 2015 · 13 comments

Comments

@qiukeren
Copy link

@qiukeren qiukeren commented Nov 23, 2015

when using

c:=cron.New()
c.Start()
time.Sleep(5*time.Second)
c.AddFunc("* * * * * *",myfunc)

the myfunc is

func myfunc(){
fmt.Println(time.Unix(time.Now().Unix(), 0).Format("2006-01-02 15:04:05"))

the output is:(current time is 15:16:07)

2015-11-23 15:16:07  <- first in sleep 5
2015-11-23 15:16:07  <- 2nd in sleep 5
2015-11-23 15:16:07  <- 3rd in sleep 5
2015-11-23 15:16:07  <- 4th in sleep 5
2015-11-23 15:16:07  <- 5th in sleep 5
2015-11-23 15:16:07  <- truely the first second
2015-11-23 15:16:08  <- truely the second second
2015-11-23 15:16:09  <- truely the third second

However,modify cron.go from

// Run the scheduler.. this is private just due to the need to synchronize
// access to the 'running' state variable.
func (c *Cron) Run() {
    // Figure out the next activation times for each entry.
    now := time.Now().Local()
    for _, entry := range c.entries {
        entry.Next = entry.Schedule.Next(now)
    }

    for {

        // Determine the next entry to run.
        sort.Sort(byTime(c.entries))

To

// Run the scheduler.. this is private just due to the need to synchronize
// access to the 'running' state variable.
func (c *Cron) Run() {
    // Figure out the next activation times for each entry.
-   now := time.Now().Local()                                 <--------------assigned 'new' before the for loop
-   for _, entry := range c.entries {                      
-       entry.Next = entry.Schedule.Next(now)
-   }                                                                     

    for {
+       now := time.Now().Local()                     
+       for _, entry := range c.entries {              
+           entry.Next = entry.Schedule.Next(now) 
+       }                                                                      

        // Determine the next entry to run.
        sort.Sort(byTime(c.entries))

may solve this problem.

@qiukeren
Copy link
Author

@qiukeren qiukeren commented Nov 23, 2015

The upper is a small modification of robfig/cron ,which can assign the cron entryid one self(it's useful to me).

what's more,cron.v2

@elgs
Copy link

@elgs elgs commented Nov 23, 2015

You code won't compile. I guess you wanted to say c:=cron.New(). Also did you mean to let the code sleep 5 milliseconds or 5 seconds?

@qiukeren
Copy link
Author

@qiukeren qiukeren commented Nov 23, 2015

@elgs sorry sir.

it's time.Sleep(5*time.Second)

@qiukeren
Copy link
Author

@qiukeren qiukeren commented Nov 23, 2015

@elgs
A full demo is here:(the upper is just extracted from my project so it is incomplete)
工程代码不太好泄露,下面是刚刚写的完整的测试:

$ cat a.go 
package main

import (
    "fmt"
    "gopkg.in/robfig/cron.v2"
    "time"
)

func main() {
    c := cron.New()
    c.Start()
    time.Sleep(5 * time.Second)
    c.AddFunc("* * * * * *", myfunc)
    select {}
}

func myfunc() {
    fmt.Println(time.Unix(time.Now().Unix(), 0).Format("2006-01-02 15:04:05"))
}
$ go run a.go 
2015-11-23 17:49:40  <-sleep 1
2015-11-23 17:49:40  <-sleep 2
2015-11-23 17:49:40  <-sleep 3
2015-11-23 17:49:40  <-sleep 4
2015-11-23 17:49:40  <-sleep 5
2015-11-23 17:49:41 第一秒
2015-11-23 17:49:42 第二秒

if c.Remove some function halfway and then c.AddFunc ,the result is alike.
the escaped time would Traversal again.
另外,如果中途停掉这个任务,然后再启动的话,效果也是(任务会把被停止的时间遍历一遍,多到几十秒少到几秒都是这样。)

@elgs
Copy link

@elgs elgs commented Nov 23, 2015

It looks like you are running a modified version of cron.

Here is my test code:

package main

import (
    "fmt"
    "github.com/robfig/cron"
    "time"
)

func main() {
    myfunc()
    fmt.Println("Run!")
    c := cron.New()
    c.Start()
    time.Sleep(5 * time.Second)
    c.AddFunc("* * * * * *", myfunc)
    select {}
}
func myfunc() {
    fmt.Println(time.Unix(time.Now().Unix(), 0).Format("2006-01-02 15:04:05"))
}

And here is the output:

2015-11-23 01:55:45
Run!
2015-11-23 01:55:50
2015-11-23 01:55:50
2015-11-23 01:55:50
2015-11-23 01:55:50
2015-11-23 01:55:50
2015-11-23 01:55:51
2015-11-23 01:55:52
2015-11-23 01:55:53
2015-11-23 01:55:54

Oh no, you are right. The result looks terribly wrong.

@qiukeren
Copy link
Author

@qiukeren qiukeren commented Nov 23, 2015

modified version of cron?
no
gopkg/cron.v2 is just a map to the github github.com/robfig/cron with tag or release = v2/2.0

2015-11-23 01:55:50

The problem is, at this second,the function was repeated five times.
(In my opinion, the function should start at 2015-11-23 01:55:51,when we use c.AddFunc() )

@elgs
Copy link

@elgs elgs commented Nov 23, 2015

After spending 2 hours loading everything back into my brain, I'm pretty sure this is a bug. The bug is triggered if the duration (t seconds) between the time c.Start() is invoked and the first time c.AddFunc() is invoked is longer than 1 second (since SpecSchedule.Next() resolution is 1 second), the entry.Next doesn't have a chance to be updated, so effective remains outdated, causing c.Next being called multiple times (t times) to catch up. Each invocation of e.Next = e.Schedule.Next(effective) moves e.Next and effective one second forward.

@qiukeren's fix is correct. Moving these lines:

now := time.Now().Local()
for _, entry := range c.entries {
    entry.Next = entry.Schedule.Next(now)
}

into the loop will give the e.Next a chance to be updated, so that effective in turn can be updated. By moving the code above into the loop, the line now = time.Now().Local() near the end of the same loop is not necessary.

Thanks @qiukeren for reporting this bug. I have also fixed the same problem in my derivation https://github.com/elgs/cron.

@elgs
Copy link

@elgs elgs commented Nov 27, 2015

@robfig, have you had a chance to take a look at this issue? I don't think it's a small bug, especially in the use cases where jobs are added sometime after cron Started?

@robfig
Copy link
Owner

@robfig robfig commented Nov 28, 2015

Ah, good catch. I wonder if it's possible to avoid re-sorting on every iteration; maybe it would be sufficient to sort initially and when jobs are added?

Thank you!

@elgs
Copy link

@elgs elgs commented Nov 29, 2015

I think re-sorting on every iteration is necessary, unless all jobs follow the same cron spec. A monthly job at the top of the queue after its run might just fall to the tail of the queue.

@robfig
Copy link
Owner

@robfig robfig commented Nov 30, 2015

OK, makes sense.

@qiukeren
Copy link
Author

@qiukeren qiukeren commented Dec 1, 2015

你们肯定有基情。
Bromance.

@tdterry
Copy link
Contributor

@tdterry tdterry commented Mar 22, 2016

The sort is necessary, but recalculating all of the entries' Next times is not. All that is needed is to use the actual current time when a new job is scheduled rather than the (possibly old) value stored in "now".

tdterry added a commit to tdterry/cron that referenced this issue Mar 22, 2016
@robfig robfig closed this in #52 Mar 28, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

4 participants