Open imxyb opened 4 years ago
@RussellLuo
@imxyb 你好,谢谢关注!
m.tw
是如何初始化的?tick 和 wheelSize 的值是多少?m.tw
里只有这一个 703726s 的任务吗?如果还有别的任务,数量和时间间隔分布大概是怎样的?@RussellLuo
tw := timingwheel.NewTimingWheel(time.Millisecond, 3600)
tw.Start()
好的。这两天比较忙,我周末分析一下。
我用如下代码尝试复现:
package main
import (
"fmt"
"time"
"github.com/RussellLuo/timingwheel"
)
func main() {
tw := timingwheel.NewTimingWheel(time.Millisecond, 3600)
tw.Start()
defer tw.Stop()
exitC := make(chan time.Time, 1)
tw.AfterFunc(703726 * time.Second, func() {
exitC <- time.Now().UTC()
})
fmt.Printf("Task created at: %v\n", time.Now().UTC())
fmt.Printf("Task executed at: %v\n", <-exitC)
}
目前为止(2020-04-04 03:10:00 +0000 UTC),任务还没有执行:
$ go run main.go
Task created at: 2020-04-02 13:09:30.229318917 +0000 UTC
时间间隔为几个月或几年的任务,由于时间成本太高,短时间很难尝试。
如果有更好的思路和排查手段,欢迎一起探讨 @imxyb
@RussellLuo 日志有时间的,时间确实是3-11日,我这边可以在poll的时候加个日志观察下。感谢你的帮忙,我这边有进展也会继续在这同步。
遇到类似的问题,两个连接同时连上之后分别调用 ScheduleFunc
func (this_ *Session) Next(prevTime time.Time) time.Time {
if this_.isClose() {
return time.Time{}
}
return prevTime.Add(time.Second * 2)
}
然后出现调用延迟的状况
2020-09-23T14:59:52.772+0800 DEBUG tcp/acceptor.go:93 session connected {"local": "127.0.0.1:9999", "remote": "127.0.0.1:55229"}
2020-09-23T14:59:52.772+0800 DEBUG tcp/acceptor.go:93 session connected {"local": "127.0.0.1:9999", "remote": "127.0.0.1:55230"}
2020-09-23T14:59:54.771+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T14:59:56.773+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T14:59:58.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:00.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:02.401+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:02.401+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:02.401+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:02.401+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:02.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:04.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:06.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:08.771+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55230", "session name": "", "session id": ""}
2020-09-23T15:00:10.400+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:10.400+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:10.400+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:10.400+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:10.771+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:12.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:14.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
2020-09-23T15:00:16.772+0800 DEBUG tcp/session.go:196 send ping msg success {"remote": "127.0.0.1:55229", "session name": "", "session id": ""}
Debugger finished with exit code 0
正常情况应该是 "remote": "127.0.0.1:55229"和"remote": "127.0.0.1:55230" 交叉出现,但是现在是成堆出现,间隔时间应该是2s.时间出现得也很奇怪
@RussellLuo 空了看一下,我感觉是同一毫毛内不能有多个任务,从目前观察来看,同一MS只会执行一个任务,剩下得任务会隔N个间隔时间之后批量出来
代码如下:
我打印的日志:
也就是说会在703726秒后执行,大概是8天左右,但是这个任务第二天就执行了。。而且这是偶发的问题,是因为我这个时间间隔过大导致的吗