詳解如何解決golang定時器引發(fā)的id重復(fù)問題
問題描述
線上服務(wù)日志中突然出現(xiàn)很多主鍵沖突的異常,而這個主鍵是一個int64的id,這個id的生成依賴了秒級時間戳和機(jī)器碼.那么下面先把問題代碼貼出來,由于具體分析較長,這里先簡述下根因,后面不感興趣可以不看
簡述根因
本質(zhì)上是golang運行時的單調(diào)時鐘和物理世界的墻上時鐘不一致導(dǎo)致的。
當(dāng)golang的單調(diào)時鐘跑過1s后,會獲取墻上時鐘并塞到ticker.C中,上述兩個操作并不同時,也不是同一個時間。
【單調(diào)時鐘沒有單位】
- 在單調(diào)時鐘1000的時候,隔了0,調(diào)用了time.Now(),得到了XX:XX:11:9999;
- 在單調(diào)時鐘2000的時候,隔了2,調(diào)用了time.Now(),得到了XX:XX:12:0001;
- 在單調(diào)時鐘3000的時候,隔了0,調(diào)用了time.Now(),得到了XX:XX:12:9999;
- 在單調(diào)時鐘4000的時候,隔了3,調(diào)用了time.Now(),得到了XX:XX:14:0002;
我們對比1,2,發(fā)現(xiàn)間隔超過了1s。對比2,3,發(fā)現(xiàn)間隔小于1s。
問題代碼
func init() { // 先設(shè)置最初的時間,保證基本的正確性 now := time.Now() updateUnixTimestamp(uint64(now.Unix())) var err error g, err = NewGenerator() if err != nil { panic(fmt.Sprintf("init default generator failed. err=%v", err)) } g2, err = NewGenerator() if err != nil { panic(fmt.Sprintf("init second default generator failed. err=%v", err)) } go func() { // sleep到下一秒開始,再創(chuàng)建一個ticker,盡量從某一秒的開始 time.Sleep(time.Until(time.Now().Truncate(time.Second).Add(time.Second))) tk := time.NewTicker(time.Second) // ticker的更新會從下一秒開始,當(dāng)前的這一秒還是需要立刻更新 now = time.Now() updateUnixTimestamp(uint64(now.Unix())) for { // 拿到這個ticker chan返回的時間 now = <-tk.C updateUnixTimestamp(uint64(now.Unix())) } }() } // 為所有的generator設(shè)置時間counter func updateUnixTimestamp(timestamp uint64) { atomic.StoreUint64(&gUnixTimestamp, timestamp) tsHigh := timestamp << 32 gGeneratorsMutex.Lock() for i := range gGenerators { atomic.StoreUint64(&gGenerators[i].timestampCounter, tsHigh) } gGeneratorsMutex.Unlock() } func (i *Generator) NextUint64() uint64 { c := atomic.AddUint64(&i.timestampCounter, 1) return (c & high32) | ((c & low16) << 16) | i.Config.workerID16 }
根因分析
從上面的方法中可以看出,這個id生成依賴了秒級時間戳和機(jī)器碼,機(jī)器碼我們已經(jīng)排查了不會重復(fù),那么最可能得原因就是時間戳重復(fù)導(dǎo)致,起初我們懷疑是ntp服務(wù)問題導(dǎo)致的時間回退,但是排查后發(fā)現(xiàn)ntp并沒有問題,我們把懷疑的方向轉(zhuǎn)向go的timer實現(xiàn),下面我們來看go的timer實現(xiàn)
timer實現(xiàn)
目前線上的服務(wù)使用的是Go 1.20版本,我們看下go 1.20版本的go ticker如何觸發(fā)運行的,這里不會展示完整的timer實現(xiàn)鏈,如果想了解timer整體實現(xiàn)可以參考 深入解析go Timer 和Ticker實現(xiàn)原理
NewTicker
我們先看下ticker初始化,重點關(guān)注sendTime(也就是后續(xù)的f)
可以看到ticker是觸發(fā)sendTime時才去獲得的最新時間,并嘗試塞給了channel,如果channel滿了則丟棄
startTimer這個實現(xiàn)不再展示(使用的是runtime包的startTimer),大致邏輯是把這個timer綁定到proccesser上,并放到這個processer的timer堆中相應(yīng)的位置上
func NewTicker(d Duration) *Ticker { if d <= 0 { panic(errors.New("non-positive interval for NewTicker")) } // Give the channel a 1-element time buffer. // If the client falls behind while reading, we drop ticks // on the floor until the client catches up. c := make(chan Time, 1) t := &Ticker{ C: c, r: runtimeTimer{ when: when(d), period: int64(d), f: sendTime, arg: c, }, } startTimer(&t.r) return t } // sendTime does a non-blocking send of the current time on c. func sendTime(c any, seq uintptr) { select { case c.(chan Time) <- Now(): default: } }
runtimer
我們看下1.20的go如何運行的timer
func runtimer(pp *p, now int64) int64 { for { t := pp.timers[0] if t.pp.ptr() != pp { throw("runtimer: bad p") } switch s := t.status.Load(); s { case timerWaiting: if t.when > now { // Not ready to run. return t.when } if !t.status.CompareAndSwap(s, timerRunning) { continue } // 重點就是這個方法 runOneTimer(pp, t, now) return 0 case timerDeleted: // 下面的邏輯對這個問題沒有影響 忽略 ..... } } func runOneTimer(pp *p, t *timer, now int64) { f := t.f arg := t.arg seq := t.seq if t.period > 0 { // 對于ticker 會先設(shè)置下次運行的時間,然后重新觸發(fā)堆排序 delta := t.when - now // t.when 一定小于等于 now,所以delta是個負(fù)數(shù) // 整數(shù)除整數(shù),得到的還是整數(shù)。 // delta一般會比t.period小特別多 (在1s的ticker下,t.period也已經(jīng)是10^6了) // 所以這個除法的結(jié)果大概率是0,所以這里的加減不太影響 t.when t.when += t.period * (1 + -delta/t.period) if t.when < 0 { // check for overflow. t.when = maxWhen } siftdownTimer(pp.timers, 0) if !t.status.CompareAndSwap(timerRunning, timerWaiting) { badTimer() } updateTimer0When(pp) } else { // Remove from heap. dodeltimer0(pp) if !t.status.CompareAndSwap(timerRunning, timerNoStatus) { badTimer() } } unlock(&pp.timersLock) // 觸發(fā)sendTimer f(arg, seq) lock(&pp.timersLock) }
從上面的代碼其實就可以看到問題了,下次觸發(fā)的時間和sendTime拿到的時間不是一致的,也就是說如果unlock或者其他操作執(zhí)行的較慢,那很可能sendTime這次拿到的時間是比預(yù)期晚,而下次拿到的時間比預(yù)期早,正好這個id生成器盡量從整秒開始,當(dāng)出現(xiàn)上面描述的情況就會出現(xiàn)兩次在同一秒的情況,導(dǎo)致id重復(fù),同時當(dāng)go調(diào)度器較忙時,可能觸發(fā)runtimer的時間比預(yù)期晚,這個時候相當(dāng)于返回的時間大于1s了,很可能又把之前小于1s的誤差追平了,這個時候如果再出現(xiàn)小于1s的情況,可能又會觸發(fā)id重復(fù)。所以日志中會看到多次出現(xiàn)id重復(fù)問題
驗證
我們寫一個很簡單的ticker
package main import ( "fmt" "time" ) func main() { // 為了更容易復(fù)現(xiàn)問題,這里盡量從接近整秒但不足整秒開始 time.Sleep(time.Until(time.Now().Truncate(time.Second).Add(999099999 * time.Nanosecond))) tick := time.NewTicker(1 * time.Second) for i := 0; i < 5; i++ { c := <-tick.C fmt.Println("tick", i, ":", c.Format(time.StampNano)) } }
然后修改sendTime方法,我們記錄下上次觸發(fā)的時間戳,然后和這次的時間戳比較
var pre int64 // sendTime does a non-blocking send of the current time on c. func sendTime(c any, seq uintptr) { var n = runtimeNano() println("send", n-pre) pre = n select { case c.(chan Time) <- Now(): default: } }
測試結(jié)果
可以看到這個sendTime的間隔先是不足1s后又超過1s,5次ticker中出現(xiàn)了2次落到同一秒的情況
觀察上述的輸出,和【簡述根因】中的推演結(jié)果一致。結(jié)論成立。
到此這篇關(guān)于詳解如何解決golang定時器引發(fā)的id重復(fù)問題的文章就介紹到這了,更多相關(guān)golang定時器引發(fā)id重復(fù)內(nèi)容請搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家!
相關(guān)文章
Go語言題解LeetCode1260二維網(wǎng)格遷移示例詳解
這篇文章主要為大家介紹了Go語言題解LeetCode1260二維網(wǎng)格遷移示例詳解,有需要的朋友可以借鑒參考下,希望能夠有所幫助,祝大家多多進(jìn)步,早日升職加薪2023-01-01使用golang如何優(yōu)雅的關(guān)機(jī)或重啟操作示例
這篇文章主要為大家介紹了使用golang如何優(yōu)雅的關(guān)機(jī)或重啟操作示例,有需要的朋友可以借鑒參考下,希望能夠有所幫助,祝大家多多進(jìn)步早日升職加薪2022-04-04Go語言通過chan進(jìn)行數(shù)據(jù)傳遞的方法詳解
這篇文章主要為大家詳細(xì)介紹了Go語言如何通過chan進(jìn)行數(shù)據(jù)傳遞的功能,文中的示例代碼講解詳細(xì),感興趣的小伙伴可以跟隨小編一起了解一下2023-06-06