35 一個單執行緒CacheService不生效的問題 (未解決)
前言
問題 就出在一下方法上面, 此方法 是一個 實體的LocalService[主要是增加了一層快取, 以及當前實體相關的一些其他的工具方法]
public XXEntity getEntity(String code) { XXEntity entity = cacheService.getOrNull(CacheConstants.CACHE_LOCAL_XX_ENTITY, code, XXEntity.class); if (entity != null) { return entity; } // ??? mapBasedCacheService ???, 你妹 一個執行緒, 怎麼會 多次跑到這裡?, 還是 jit 優化導致的?? 2018.10.26 // 然後 今天列印了一下彙編?, 又或者是 試用了一下 NonExpireMapBasedCacheService?, 結果 不管怎樣又都復現不出來了??? 2018.10.30 entity = XXEntityBaseService.get(code); if (entity == null) { LOGGER.error(" 發現一個未知的 XXEntity : " + code); entity = DUMMY; } cacheService.set(CacheConstants.CACHE_LOCAL_XX_ENTITY, code, JSON.toJSONString(entity), localCacheInSecs); return entity; }
呼叫這個方法的地方是外面的有一層迴圈, 迴圈各個訂單資訊, 來處理業務, 處理業務的過程中需要獲取不同的 XXEntity 來輔助業務
然後 獲取 XXEntity 這個地方, 在上上週五的時候, 就特麼神奇了, cacheService 好像是沒生效似得, 同一個 code, 觸發了 N[多] 次的 "XXEntityBaseService.get"[讀庫的操作], 是通過 列印日誌發現的
問題的嘗試
第一次嘗試 :
然後, 之後 我在上面 "XXEntityBaseService.get(code)" 打了一個斷點, 然後往下走, entity 拿到的是 null, 然後 走後面列印日誌 以及 更新 entity 為 DUMMY
然後 走後面的 "cacheService.set", 然後 我看 cacheService 裡面也有儲存的相關的資料, 然後 就放了斷點, 然後 此時走是正確的結果, 各個 XXEntity 只獲取了一次[讀庫的操作]
第二次嘗試 :
同樣, 在在上面 "XXEntityBaseService.get(code)" 打了一個斷點, 然後繼續 放斷點, 到下一個訂單[迴圈的下一個訂單]走當前斷點, code 和上面的一樣, 然後 執行緒也和上面的一樣
特麼的 第二個斷點這個是怎麼來的??, 單執行緒往下週的時候 第一個斷點的時候 就應該會 "cacheService.set", 往快取裡面放進去啊, 然後 理論上來說是不應該 同一個code, 同一個執行緒 再一次到達這個斷點[快取的有效時間 遠遠大於 這裡兩個斷點的時間差]
然後 再放這個斷點到下一個訂單, 還是這個 code, 這條執行緒, 居然 又進了 斷點???, 你妹 這特麼什麼情況???
然後 在第二次斷點 和第三次斷點 看了一下 cacheService 裡面的資料結構, entity 似乎是沒有放進去??, 難道是 根本沒有跑 "cacheService.set" 相關的程式碼?
然後 上面第一次嘗試的時候, debug 單步跑的時候走了 "cacheService.set", 然後 就往 cacheService 裡面放入了快取的東西, 而這裡直接方了斷點 沒有跑 "cacheService.set" 相關的程式碼? 是什麼情況
第三次嘗試 : 我覺得可能是 由於某些 "優化", 導致了出現這個問題?, 然後 我稍微改了一下程式碼, 改成了如下情況, 也就是 吧 "cacheService.set" 放到了 "XXEntityBaseService.get" 後面的第一條語句
public XXEntity getEntity(String code) {
XXEntity entity = cacheService.getOrNull(CacheConstants.CACHE_LOCAL_XX_ENTITY, code, XXEntity.class);
if (entity != null) {
return entity;
}
entity = XXEntityBaseService.get(code);
cacheService.set(CacheConstants.CACHE_LOCAL_XX_ENTITY, code, (entity == null) ? JSON.toJSONString(DUMMY) : JSON.toJSONString(entity), localCacheInSecs);
if (entity == null) {
LOGGER.error(" 發現一個未知的 XXEntity : " + code);
entity = DUMMY;
}
return entity;
}
然後 嘗試跑了一下程式, 或者 debug, 然後直接 放斷點 進下一個訂單, 然後 發現沒有這個問題了, 似乎 cacheService 又生效了???
第四次嘗試 : 然後 又嘗試修改了一下程式碼, 改成了如下的樣子, 實際效果沒有太大的變化, 改了一種寫法而已
public XXEntity getEntity(String code) {
XXEntity entity = cacheService.getOrNull(CacheConstants.CACHE_LOCAL_XX_ENTITY, code, XXEntity.class);
if (entity != null) {
return entity;
}
entity = XXEntityBaseService.get(code);
entity = (entity == null) ? DUMMY : entity;
cacheService.set(CacheConstants.CACHE_LOCAL_XX_ENTITY, code, JSON.toJSONString(entity), localCacheInSecs);
if(entity == DUMMY) {
LOGGER.error(" 發現一個未知的 XXEntity : " + code);
}
return entity;
}
然後 嘗試跑了一下程式, 或者 debug, 然後直接 放斷點 進下一個訂單, 然後 這個問題又出現了??, 似乎 cacheService 又不生效了???
一些上下文
然後 後面還有幾次嘗試, 還得交代一些東西, 上面的情況發生的時候 cacheService 是一個 MapBasedCacheService 例項, 也就是 自己寫的一個 基於Map的一個快取[帶過期時間處理, 處理的方式是獲取之間 判斷快取的實體是否過期, 過期移除, 並返回 null]
然後 我的實現裡面, 還有另外一個 RedisBasedCacheService, 是直接 基於 redis 做的一個 CacheService
涉及到 這裡的介面, 一個就是 放入資料到快取的操作, 以及一個從快取中拿資料的操作
第五次嘗試 : 然後 我把 cacheService 改回了 RedisBasedCacheService 例項, 然後 發現 有沒有問題了??, cacheService 又生效了???
第六次嘗試 : 然後 我把 MapBasedCacheService 的程式碼調整了一下, 這裡涉及的幾個方法, set, getOrNull 加了一個 synchronized
然後 吧 cacheService 改成了 MapBasedCacheService 的例項, 然後 又跑了一次程式碼, 然後 也沒有問題???
第七次嘗試 : 我增加了一個實現 NonExpireMapBasedCacheService, 簡單的使用一個 Map 來進行存取, 然後 不做超時過期的處理, 直接 set, put
然後 吧 cacheService 改成了 NonExpireMapBasedCacheService 的例項, 然後 又跑了一次程式碼, 然後 也沒有問題???
結果..
然後 最終並沒有發現問題 到底是出現在什麼地方,, 然後 上週二的時候, 在準備回來 看下這個問題[上面的第六次, 第七次嘗試 就是週二做的]
然後 我就想啊, 媽的 單執行緒 還能玩出這樣的花樣, 是什麼情況??, 然後 我想列印一下 jit 編譯之後的彙編, 看下 會出現這個問題的時候, 和不出現這個問題的時候的 彙編到底會有什麼區別 ??
然後 這裡直接 給一下最後的結果 : 沒有找到原因 !
因為 後來的這個 現象就沒有再重現了, 然後 打印出來的彙編 也只是中規中矩的正常結果, 兩個彙編, 應該是 C1 一個, C2 一個, 有時候 會只出現一個
這個問題, 就只有看看 之後能不能再復現了, 有緣的話, 我還是希望知道 造成這個問題的原因
------------------------------------------ 分割線 ------------------------------------------------
關於 PrintAssembly 和 JITWatch
然後 雖然這個奇葩的問題 沒有找到原因, 但是 也還是有一些收貨的, 看了一下 打印出來的彙編
還有就是 用 JITWatch, 解析了一下
列印目的碼的彙編 [編譯模式啟動]
-server -Xcomp -XX:+UnlockDiagnosticVMOptions -XX:+PrintAssembly -XX:CompileCommand=compileonly,*LocalXXEntityService.getEntity 生成編譯日誌 [編譯模式啟動]
-server -Xcomp -XX:+UnlockDiagnosticVMOptions -XX:+PrintAssembly -XX:+LogCompilation -XX:LogFile=live.log如果 不想以編譯模式啟動, 可以"手動多次呼叫", 達到 jit 編譯的標準
跑了之後 生成日誌, 然後 之後 使用 JITWatch 分析日誌, 或者 直接從 console 裡面拿到想要的 彙編程式碼
不過 JITWatch, 看起來 自然是要簡單明瞭一些
PrintAssembly 選項所需要的庫檔案, 可以從下面地址下載
http://hllvm.group.iteye.com/
https://download.csdn.net/download/yizishou/9699103
不過 iteye 裡面下載需要加入群組, csdn 這個下載所需要的分數太貴了, 因此 我也上傳了一個
JITWatch 專案的 github
https://github.com/AdoptOpenJDK/jitwatch
直接下載下來, 執行 jitwatch-ui 模組 裡面的 main 方法即可, 或者 照著參考的文章下載 給定的jar, 來執行
執行起來效果如下
good luck !
參考
https://blog.csdn.net/hengyunabc/article/details/26898657
https://github.com/AdoptOpenJDK/jitwatch