jonboulle / clockwork

a fake clock for golang
Apache License 2.0
656 stars 58 forks source link

fakeTicker doesn't work as expected #60

Closed seaguest closed 1 year ago

seaguest commented 1 year ago

Hi,

    fc := clockwork.NewFakeClock()

    ft := fc.NewTicker(1)
    fc.Advance(3)

    select {
    case x := <-ft.Chan():
        fmt.Println("1-------------", x)
    default:
    }

I am expecting have 3 print in above code, but it only print once, looks like the ticker is only triggered once, how can I trigger multiple times?

DPJacques commented 1 year ago

There is no loop in the code above. It will only ever print once.

Also keep in mind ticks that are not received before the follow on tick are dropped: "The ticker will adjust the time interval or drop ticks to make up for slow receivers" - https://pkg.go.dev/time#Ticker

To accomplish what you want without race conditions, you need 3 goroutines running waiting on the tick, then call Advance(3). You should see each once of them fire once.

seaguest commented 1 year ago
func main() {
    fc := clockwork.NewFakeClock()
    ft := fc.NewTicker(1)

    for i := 0; i < 3; i++ {
        go func() {
            select {
            case x := <-ft.Chan():
                fmt.Println("1-------------", x)
            default:
                fmt.Println("2-------------")
            }
        }()
    }

    fc.Advance(3)
    time.Sleep(time.Second)
}

-----OUTPUT----
2-------------
1------------- 2006-01-02 15:04:05.000000001 +0000 UTC
2-------------
DPJacques commented 1 year ago

The default: case in your switch conditions leads you to race conditions. You are asking the program to run through the for loop as fast as possible, sidestepping the channel read if it can, so that is what happens. You just happen to catch 1 of the ticks in the code you have above.

From clockwork's perspective, this is all working as intended. The caller side code is setting up a race condition.

seaguest commented 1 year ago

@DPJacques

Thanks for your reply! it always print once even I removed the default case, it prints twice occasionally sometime. I did a time.Sleep at the end to leave ticker enough time to get triggered.

DPJacques commented 1 year ago

This is because the go routines have not started by the time fc.Advance(3) has completed, once again there is a race condition. If you add a time.Sleep(1) before your fc.Advance(3) you should see most of them.

However, you are still inducing race conditions on the clockwork.Ticker interface. Even with the time.Sleep, you are only delaying for an arbitrary amount of time in hopes that the goroutines are all setup and blocking by the time you call fc.Advance(3). Pragmatically, this is almost always true, but niether Go or clockwork can't guarantee that, because it depends on the runtime scheduler.

The root cause is that clockwork.Ticker can't guarantee to send all ticks while also remaining consistent with the time.Ticker API, becuase this is not a guarantee the time.Ticker API makes.

If you want to avoid race conditions, you need to advance past every tick individually. If you don't do this, there will always be some amount of race condition in your code. There are ways to minimize those race conditions, but they will still be present. In all cases, clockwork is working as intended.

@sagikazarmark I think it would be reasonable to close this issue out as working as intended.

DPJacques commented 1 year ago

Example of what I refer to in my comment above, the following code prints nothing:

func main() {
    fc := clockwork.NewFakeClock()
    ft := fc.NewTicker(1)

    for i := 0; i < 3; i++ {
        i := i
        go func() {
            fmt.Println("started: ", i)
            select {
            case x := <-ft.Chan():
                fmt.Println(i, " time: ", x)
            }
        }()
    }

    fc.Advance(3)
}
DPJacques commented 1 year ago

Another example:

func main() {
    fc := clockwork.NewFakeClock()
    ft := fc.NewTicker(1)

    for i := 0; i < 3; i++ {
        i := i
        go func() {
            fmt.Println("started: ", i)
            select {
            case x := <-ft.Chan():
                fmt.Println(i, " time: ", x)
            }
        }()
    }

    fc.Advance(3)
    fmt.Println("advanced")
    time.Sleep(time.Second)
}

Output:

advanced
started:  2
2  time:  2006-01-02 15:04:05.000000001 +0000 UTC
started:  1
started:  0
sagikazarmark commented 1 year ago

@sagikazarmark I think it would be reasonable to close this issue out as working as intended.

I tend to agree.

@seaguest a couple more comments that hopefully understand you what's happening:

@DPJacques's examples accurately represent all that.

If you still believe there is a bug somewhere, please provide a test case or an example that proves there is one.

Hope this helps!