今天同事反饋了一個問題,之前看到沒有太在意,雖然無傷大雅,但是想如果不重視,那麼後期要遇到的問題就層出不窮,所以就作為我今天的任務之一來看看吧。能不能定位和解決,當然從事後來看,也算是找到了問題處理的一個通用思路。
問題的現象很明顯:GPCC工具可以顯示出GP的日誌內容,但是和GP日誌裡的時間明顯不符。
GPCC的一個截圖如下,簡單來說就好比Oracle的OEM一樣的工具。能夠檢視叢集的狀態,做一些基本資訊的收集和視覺化展現。紅色框圖的部分就是顯示日誌中的錯誤資訊。
我把日誌內容放大,方便檢視。
以下是從GPCC中擷取到的一段內容。
擷取一段GPCC中的內容供參考。
03 Apr14:18:07
ERROR
MPP detected 1 segment failures, system is reconnected (cdbfts.c:228)
u:datax_userdb:TESTDB host:10.xxxx
而GP的日誌顯示如下:
2018-04-03 00:18:07.055801 CST,
"datax_user","TESTDB",p173295,th972601120,"10.xxxx","64523",2018-04-03 00:17:40 CST,1811909,con659620,cmd1,seg-1,,dx572994,x1811909,sx1,"ERROR","XX000","MPP detected 1 segment failures, system is reconnected (cdbfts.c:228)",,,,,"COPY test_map, line 11705805: ""20150826|38377|5364390|1|1|1|1|1|1|1|1|1|1|1|1|1|1|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|0|2018-04-03 00:1.
..""","COPY test.test_map ( xxxx) FROM STDIN delimiter as '|' NULL 'null' ",0,,"cdbfts.c",228,"Stack trace:
1 0xb0aefe postgres errstart (elog.c:502)
2 0xc29d9f postgres FtsHandleNetFailure (cdbfts.c:227)
3 0xbd4ca5 postgres cdbCopyEndAndFetchRejectNum (cdbcopy.c:804)
4 0x6b757a postgres CopyFromDispatch (copy.c:3823)
5 0x6c6c9c postgres DoCopyInternal (copy.c:1767)
6 0x6c8388 postgres DoCopy (copy.c:1883)
7 0x9a5f9d postgres ProcessUtility (utility.c:1100)
8 0x9a364b postgres PortalRun (pquery.c:1505)
9 0x99a5bc postgres <symbol not found> (postgres.c:1811)
10 0x99e9b9 postgres PostgresMain (postgres.c:4760)
11 0x8f8dfe postgres <symbol not found> (postmaster.c:6672)
12 0x8fba90 postgres PostmasterMain (postmaster.c:7603)
13 0x7fbeff postgres main (main.c:206)
14 0x37f901ed1d libc.so.6 __libc_start_main + 0xfd
15 0x4be869 postgres <symbol not found> + 0x4be869
"
根據時間情況來看,gpcc中顯示的時間明顯比GP日誌的要快,認真對比了下,按照精度來算,快了14個小時。
還有一個問題是錯誤日誌中提到的segment failure是什麼意思,是否能給出一個解釋。
所以我們還是得回到GP日誌,需要結合上下文內容來做一個理解,回放出在那個時間點的操作。往前看很快就定位到了相關的日誌,原來是在做一批次的copy操作,很可能因為網路抖動導致其中一個copy操作阻塞。
所以錯誤資訊的基本結論如下:
透過日誌可以明確在GP做copy的過程中很可能出了網路問題導致操作受阻,GP嘗試重新連線segment
基本解釋清了問題,我們再來看下本質的問題,為什麼系統中和日誌中的時間戳不同,妥妥的差了14個小時。
所以很自然的,我們會丟擲一個問題:資料是怎麼從日誌傳輸到前端的?
換個問題就是資料是如何從後端傳輸到前端,初步的方向就是時區上面,但是我檢視了部署的軟體配置,並沒有關於時區的配置。
在諮詢了一些朋友之後,我決定再看看官方是否有相關的解釋。
花了點力氣,所幸找到一篇,還是在3月底更新的一篇,這個時候碰到這個問題算是很應景了。
連結如下:
https://discuss.pivotal.io/hc/en-us/articles/115005976807-Timestamp-mismatch-alerts-in-Greenplum-Command-Center-in-China-Standard-Timezone
話外音就是搜尋還是要講究點技巧,要不搜尋不出來確實很尷尬。官方的建議,其實就是因為時區的特定設定,也可以理解是一個bug,在實現的時候,對於中文支援的原因導致了這個問題,如果要做一個WA,可以重置GPCC的檔案庫和使用者的timezone,當然還需要重啟GP叢集生效,修改後的日期時間戳就顯示不是CST,而是HKT,可能還需要評估下是否有其他的影響範圍。
所以對於時間問題不一致的基本結論如下:
這個是GPCC的一個問題,在3.x版本出現,在低版本也是同樣的。
要修復這個問題,需要重新設定時區的配置,重新GP叢集,可以考慮後續是否有機會來做下這個問題的修復。前提還是在測試環境充分測試驗證。目前先保持現狀。