CPU時(shí)間都去哪了:一步步定位數(shù)據(jù)庫(kù)代碼中的性能瓶頸
前言
最近接到技術(shù)支持部門(mén)的求助,說(shuō)是有個(gè)客戶(hù)在測(cè)試我司數(shù)據(jù)庫(kù)某個(gè)版本的過(guò)程中發(fā)現(xiàn)明顯的性能問(wèn)題,希望我們能夠幫忙盡快找到原因,并提供解決方案。經(jīng)過(guò)調(diào)查研究,最終確定是由CPU cache line “false sharing” 引起的問(wèn)題。
鑒于網(wǎng)上類(lèi)似的文章較少,并且這種問(wèn)題往往在代碼中比較隱蔽,較難輕易發(fā)現(xiàn),所以在這里做個(gè)分享。如果碰巧對(duì)其他做類(lèi)似工作的人有所啟發(fā),本人將非常高興。
背景介紹
這個(gè)客戶(hù)多年來(lái)一直使用我司的數(shù)據(jù)庫(kù),目前打算升級(jí)到更高版本,但在對(duì)數(shù)據(jù)壓縮功能的測(cè)試中發(fā)現(xiàn),在某種情況下,在壓縮過(guò)的數(shù)據(jù)表上做全表掃描(table scan)所花費(fèi)的時(shí)間會(huì)隨著并發(fā)的全表掃描任務(wù)數(shù)的增多而顯著增加,而未經(jīng)壓縮過(guò)的數(shù)據(jù)表則沒(méi)有這種現(xiàn)象。
數(shù)據(jù)壓縮是我們團(tuán)隊(duì)多年前開(kāi)發(fā)的一個(gè)功能,之前做過(guò)大量的代碼優(yōu)化,性能相對(duì)比較穩(wěn)定,實(shí)在不應(yīng)該會(huì)有這樣的問(wèn)題,這也因此引起了我極大的興趣。
了解數(shù)據(jù)庫(kù)的人都知道,影響數(shù)據(jù)庫(kù)的性能的因素較多,比如服務(wù)器的硬件配置,數(shù)據(jù)庫(kù)的參數(shù)設(shè)置,數(shù)據(jù)的磁盤(pán)分布等,當(dāng)然,也不排除數(shù)據(jù)庫(kù)自身代碼的問(wèn)題,不太容易一下定位到具體的原因。一般情況下,如果能通過(guò)數(shù)據(jù)庫(kù)調(diào)優(yōu)解決問(wèn)題,就沒(méi)必要花費(fèi)大量時(shí)間去調(diào)查數(shù)據(jù)庫(kù)源代碼,所以,在整個(gè)問(wèn)題的調(diào)查研究過(guò)程中,我的原則是,先易后難,大膽猜想,逐項(xiàng)排除。
調(diào)查思路
客戶(hù)屬于金融行業(yè),對(duì)數(shù)據(jù)安全有嚴(yán)格的規(guī)定,根本不可能讓我訪問(wèn)他們的數(shù)據(jù)庫(kù)系統(tǒng)去做分析,唯一的方法就是,先本地重現(xiàn)問(wèn)題,然后調(diào)試。本地重現(xiàn)是個(gè)消耗體力和想象力的過(guò)程,索性經(jīng)過(guò)很多次的溝通和嘗試,終于重現(xiàn)了類(lèi)似的現(xiàn)象。
1)數(shù)據(jù)庫(kù)使用問(wèn)題 vs 數(shù)據(jù)庫(kù)代碼問(wèn)題
在一開(kāi)始確定這個(gè)問(wèn)題是非常必要的,它將決定接下來(lái)所花費(fèi)的時(shí)間和精力的大小。
跟客戶(hù)做了些溝通,發(fā)現(xiàn)他們對(duì)數(shù)據(jù)庫(kù)沒(méi)有比較深入的了解,所以,首先懷疑的是,有沒(méi)有可能他們的數(shù)據(jù)庫(kù)系統(tǒng)中的某些配置參數(shù)設(shè)置不合理,從而影響性能呢?
很快拿到了客戶(hù)的數(shù)據(jù)庫(kù)配置文件,逐一分析,并結(jié)合本地實(shí)驗(yàn),發(fā)現(xiàn)并無(wú)明顯的問(wèn)題,唯一的一個(gè)問(wèn)題是,某個(gè)跟數(shù)據(jù)壓縮統(tǒng)計(jì)信息相關(guān)的配置參數(shù)打開(kāi)了,這個(gè)參數(shù)主要是在分析問(wèn)題的時(shí)候使用的,生產(chǎn)環(huán)境是不建議打開(kāi)的,立即關(guān)閉了這個(gè)配置參數(shù),在本地環(huán)境中重新測(cè)試了一下,發(fā)現(xiàn)性能有些改善。
立即建議客戶(hù)也做同樣的嘗試,很快得到反饋,性能有所提升,但還未達(dá)到他們的預(yù)期。
看樣子事情沒(méi)那么簡(jiǎn)單,接下來(lái)開(kāi)始傾向于認(rèn)為,可能數(shù)據(jù)庫(kù)代碼哪里出了問(wèn)題。
2)鎖競(jìng)爭(zhēng) (lock contention)
在支持高并發(fā)的數(shù)據(jù)庫(kù)系統(tǒng)中,為了同步不同任務(wù)對(duì)一些關(guān)鍵資源的訪問(wèn),使用鎖是一種常見(jiàn)的方式,如spinlock,mutex等,但是,一旦發(fā)生嚴(yán)重的鎖競(jìng)爭(zhēng),將會(huì)極大影響數(shù)據(jù)庫(kù)系統(tǒng)的性能。雖然近些年lockless的呼聲很高,但是一個(gè)數(shù)據(jù)庫(kù)系統(tǒng)要完全做到lockless還是較難的,一般的策略是,對(duì)某些關(guān)鍵的,容易引起競(jìng)爭(zhēng)的結(jié)構(gòu)或者模塊采用lockless的方式。所以,檢查鎖競(jìng)爭(zhēng)是下一步的重點(diǎn)。
我司的這款數(shù)據(jù)庫(kù)雖然全球市場(chǎng)份額不大,但也是深耕該行業(yè)的老品牌,在國(guó)外的金融領(lǐng)域有口皆碑,在無(wú)數(shù)次市場(chǎng)檢驗(yàn)的過(guò)程中,為了更好地分析各種問(wèn)題,工程師們?cè)谙到y(tǒng)中加入了關(guān)鍵信息的統(tǒng)計(jì)功能。
通過(guò)分析一些系統(tǒng)關(guān)鍵資源的統(tǒng)計(jì)信息,并未發(fā)現(xiàn)明顯的鎖競(jìng)爭(zhēng),或者資源競(jìng)爭(zhēng),尤其是跟數(shù)據(jù)壓縮相關(guān)的,所以,這個(gè)可能的原因排除掉。
3)CPU cache相關(guān)的問(wèn)題
前兩個(gè)可能都排除了,現(xiàn)在需要重新審視下客戶(hù)的環(huán)境,尋找下一個(gè)可能的方向。
客戶(hù)的數(shù)據(jù)庫(kù)服務(wù)器有著不錯(cuò)的硬件配置,CPU core夠多,內(nèi)存夠大,數(shù)據(jù)庫(kù)中也配置了幾十個(gè)引擎(engine),可以充分利用多CPU core提升并行任務(wù)的執(zhí)行能力。
此數(shù)據(jù)庫(kù)服務(wù)器是典型的NUMA(Non-Uniform Memory Access)架構(gòu),一個(gè)系統(tǒng)有多個(gè)CPU,每個(gè)CPU里面有多個(gè)core,每個(gè)CPU core有獨(dú)享的L1和L2 cache,同一個(gè)CPU 的cores共享L3 cache(Last Level Cache,LLC)。 cache的訪問(wèn)延遲比主存要小很多,越靠近CPU,訪問(wèn)延遲越小,處理器會(huì)根據(jù)不同的策略(Inclusive Policy,Exclusive Policy等)把數(shù)據(jù)緩存在不同級(jí)別的cache中,從而加快CPU訪問(wèn)數(shù)據(jù)的速度,因?yàn)楦鶕?jù)“數(shù)據(jù)局部性原理”,目前訪問(wèn)的數(shù)據(jù)或者其相鄰數(shù)據(jù)很有可能在不久的將來(lái)會(huì)再次訪問(wèn)到。
同時(shí),cache的容量大小也比主存要小很多(如Interl處理器中的L1 data cache 大小為32k),如何優(yōu)化代碼使之有效利用cache提升系統(tǒng)性能一直一來(lái)都是個(gè)是熱門(mén)的話(huà)題,也是本問(wèn)題接下來(lái)重點(diǎn)關(guān)注的一個(gè)方向。
收集線(xiàn)索
Linux系統(tǒng)自帶的perf工具是性能分析利器,熟悉系統(tǒng)性能分析的應(yīng)該都不會(huì)陌生。接下來(lái)將介紹如何使用這個(gè)工具一步步分析問(wèn)題,并最終找到原因,我的主要的思路是,由大到小,由面到點(diǎn),關(guān)注熱點(diǎn)。
“perf stat“能夠收集采樣周期內(nèi)關(guān)于某些事件(event)的統(tǒng)計(jì)信息并顯示出來(lái),通過(guò)這些信息可以大致了解程序的運(yùn)行狀況。這里重點(diǎn)關(guān)注的是CPU和data cache,當(dāng)然,也可以根據(jù)個(gè)人需要指定其它事件進(jìn)行監(jiān)測(cè)。
- perf stat -e task-clock -e cycles -e stalled-cycles-frontend -e stalled-cycles-backend -e cache-misses -e L1-dcache-loads -e L1-dcache-load-misses -e L1-dcache-stores -e L1-dcache-store-misses -e L1-dcache-prefetches -e L1-dcache-prefetch-misses -e LLC-loads -e LLC-load-misses -p 29261 sleep 50
輸出里的一些數(shù)據(jù)比較有意思,需要重點(diǎn)關(guān)注的是,stalled CPU cycles超過(guò)了80%!
- 247906.038072 task-clock # 4.958 CPUs utilized
- 812171299976 cycles # 3.276 GHz [36.39%]
- 694124548218 stalled-cycles-frontend # 85.47% frontend cycles idle [36.40%]
- 668744885346 stalled-cycles-backend # 82.34% backend cycles idle [36.43%]
- 514323939 cache-misses # 2.075 M/sec [36.44%]
- 89260315424 L1-dcache-loads
- # 360.057 M/sec [36.41%]
- 872622317 L1-dcache-misses
- # 0.98% of all L1-dcache hits [36.39%]
- 35598131563 L1-dcache-stores
- # 143.595 M/sec [36.37%]
- 57219914 L1-dcache-misses
- # 0.231 M/sec [36.35%]
- <not counted> L1-dcache-prefetches
- 216934515 L1-dcache-misses
- # 0.875 M/sec [36.35%]
- 672308105 LLC-loads
- # 2.712 M/sec [36.35%]
- 458916465 LLC-misses
- # 68.26% of all LL-cache hits [36.34%]
接下來(lái)運(yùn)行“perf record“ 收集性能數(shù)據(jù),并用“perf report“顯示,
- perf record -p 29261 -g sleep 50
- perf report > perf_record.out
通過(guò)查看各個(gè)函數(shù)消耗CPU時(shí)間的情況,發(fā)現(xiàn)占比***的前兩個(gè)“熱點(diǎn)“函數(shù)如下 (鑒于知識(shí)產(chǎn)權(quán)的原因,對(duì)函數(shù)名進(jìn)行了一些修改,請(qǐng)勿對(duì)號(hào)入座),
- 65.73% s_dataserver s_dataserver [.] decompress__xxx_by_xxx
- |
- --- decompress__xxx_by_xxx
- |
- |--99.88%-- decompress_xxx_by_yyy
- | …
- 21.66% s_dataserver s_dataserver [.] decompress_xxx_by_yyy
很明顯,這是兩個(gè)解壓縮數(shù)據(jù)的函數(shù),由于全表掃描需要解壓縮所有數(shù)據(jù)行,檢查每一行是否符合查詢(xún)條件,所以解壓縮的函數(shù)消耗大量CPU時(shí)間也合情合理,但是消耗的CPU時(shí)間的占比確實(shí)有點(diǎn)高(這里先打個(gè)問(wèn)號(hào))。
接下來(lái)使用“perf annotate“查看指定函數(shù)內(nèi)代碼行的CPU資源消耗情況,
- perf annotate --symbol=decompress_xxx_by_yyy
有一條指令消耗了67.04%的CPU資源,(另一個(gè)熱點(diǎn)函數(shù)也是類(lèi)似的情況),非常可疑,
- 0.21 : db69d1: 49 8b 00 mov (%r8),%rax
- 12.08 : db69d4: 49 0f bf d4 movswq %r12w,%rdx
- 0.05 : db69d8: 48 89 d9 mov %rbx,%rcx
- 0.00 : db69db: 48 0f bf 14 50 movswq (%rax,%rdx,2),%rdx
- 67.04 : db69e0: 49 8b 40 08 mov 0x8(%r8),%rax
- 8.64 : db69e4: 44 0f bf 0c 50 movswl (%rax,%rdx,2),%r9d
- 7.83 : db69e9: 48 8b 87 a8 02 00 00 mov 0x2a8(%rdi),%rax
通過(guò)解析匯編指令和源代碼比對(duì),找到了這條可疑指令對(duì)應(yīng)的源代碼(由于知識(shí)產(chǎn)權(quán)的原因,對(duì)變量名進(jìn)行了一些修改,請(qǐng)勿對(duì)號(hào)入座),
- new_index = decompressinfo->xxx_arrayC[decmpressinfo->xxx_arrayB[index]]
那條消耗CPU最多的匯編指令對(duì)應(yīng)的源代碼操作是,
- xxx_arrayC[temp_index]
看到這些,你可能會(huì)有諸多疑問(wèn),
- 這個(gè)decompressinfo是什么,有什么特別之處?
- 為什么如此簡(jiǎn)單的一行代碼卻消耗了了大量的CPU時(shí)間?
- 為什么如此簡(jiǎn)單的“數(shù)組“元素訪問(wèn)也成了問(wèn)題?
分析原因
為了更好地說(shuō)明問(wèn)題,下面給出decompressinfo對(duì)應(yīng)的數(shù)據(jù)結(jié)構(gòu),并稍微解釋下與之相關(guān)的背景知識(shí)。
- typedef struct xxx
- {
- /* Arrays of different types */
- TYPEA *arrayA;
- TYPEB *arrayB;
- TYPEC *arrayC;
- TYPED *arrayD;
- /* Other variables */
- short v1;
- short v2;
- int v3;
- .................
- } XXX;
- 該結(jié)構(gòu)體大小是48字節(jié)(僅列出了部分結(jié)構(gòu)體成員,已經(jīng)足夠幫助說(shuō)明問(wèn)題,請(qǐng)勿較真)。
- 該結(jié)構(gòu)體存放的是解壓縮數(shù)據(jù)需要的信息,這些信息在全表掃描過(guò)程中不會(huì)改變。
- 該結(jié)構(gòu)體的內(nèi)存來(lái)自于數(shù)據(jù)庫(kù)內(nèi)部的一個(gè)memory pool,解壓縮的時(shí)候也會(huì)從這里分配內(nèi)存,用于臨時(shí)存放解壓縮后的數(shù)據(jù)。
- 在構(gòu)造decompressinfo的時(shí)候,首先會(huì)分配一塊足夠大小的連續(xù)內(nèi)存,內(nèi)存的前48個(gè)字節(jié)用來(lái)存放其結(jié)構(gòu)體成員,然后,幾個(gè)成員指針?lè)謩e指向剩余連續(xù)內(nèi)存的不同位置(具體位置取決于每個(gè)成員指針指向的“數(shù)組“的大小)。在本例中,其內(nèi)存布局如下,
雖然了解了這些信息,還是感覺(jué)似乎一切看起來(lái)都很正常,并無(wú)明顯不妥。
這里還需要再稍微提一下介于CPU和主存之間的cache,CPU訪問(wèn)某個(gè)虛擬內(nèi)存地址處的數(shù)據(jù)時(shí),會(huì)先嘗試cache,如果未***,便會(huì)把數(shù)據(jù)從主存加載到cache。從虛擬內(nèi)存地址到cache的映射有多種策略,如direct mapped,set associative,fully associative,硬件廠商使用較多的是set associative,這方面網(wǎng)上資料很多,本文不展開(kāi)此話(huà)題。數(shù)據(jù)加載的最小單位為一個(gè)cache line,其大小隨硬件廠商不同有差異,目前使用較多的是64字節(jié)。這樣一來(lái),加載到cache中的數(shù)據(jù)大小可能會(huì)大于實(shí)際訪問(wèn)的數(shù)據(jù),造成的結(jié)果是,如果兩個(gè)并行任務(wù)工作在連續(xù)內(nèi)存上的相鄰區(qū)域,它們私有的數(shù)據(jù)可能會(huì)被加載到同一個(gè)cache line,雖然它們并無(wú)數(shù)據(jù)共享,這個(gè)現(xiàn)象叫做共享cache line。
結(jié)合上述知識(shí),讓我們把decompressinfo放到更大的內(nèi)存空間,問(wèn)題就變得稍微清楚些了,
簡(jiǎn)單來(lái)講有如下幾點(diǎn):
- decompressinfo所在內(nèi)存塊的開(kāi)始地址和結(jié)束地址未必正好在一個(gè)cache line的起始處。
- arrayC距離整塊內(nèi)存的結(jié)束地址17字節(jié),有較大可能跟后續(xù)連續(xù)的內(nèi)存地址共享cache line。
- 如果后續(xù)連續(xù)的內(nèi)存分配給了一個(gè)執(zhí)行大量寫(xiě)操作的任務(wù),每次寫(xiě)操作將會(huì)引起該cache line 在其它CPU core的copy失效,其它CPU core在下次讀取該cache line的時(shí)候需要重新加載。這個(gè)現(xiàn)象稱(chēng)為cache line的“false sharing”,對(duì)并發(fā)任務(wù)的性能有較大影響。
驗(yàn)證結(jié)果
所有疑問(wèn)似乎都有了合理的解釋?zhuān)贿^(guò)目前這都還只是猜想,需要實(shí)踐來(lái)檢驗(yàn)。
立即優(yōu)化了相關(guān)代碼,調(diào)整了decompressinfo使用的內(nèi)存塊地址,使其cache line對(duì)齊,避免跟其它任務(wù)共享cache line。
在本地環(huán)境測(cè)試后,之前的問(wèn)題基本消失,部分測(cè)試結(jié)果如下,
優(yōu)化前
- ------------------------------------------------------------------------------
- | 并發(fā)數(shù) | CPU 時(shí)間(ms) |
- ------------------------------------------------------------------------------
- 1 49475
- 2 111005 129663
- 5 165716 165751 173644 174187 197538
- 10 198619 203565 205815 206421 207255 215240 216244 218213 220795 242982
優(yōu)化后
- ------------------------------------------------------------------------------
- | 并發(fā)數(shù) | CPU 時(shí)間(ms) |
- ------------------------------------------------------------------------------
- 1 49872
- 2 50538 50531
- 5 50897 50912 50920 50963 50350
- 10 52581 52028 52752 52758 52399 52546 53494 52302 53056 52527
再次運(yùn)行“perf annotate“,發(fā)現(xiàn)之前的問(wèn)題行消耗的CPU已經(jīng)大幅降低,
- 0.07 : e145a4: 49 0f bf d4 movswq %r12w,%rdx ▒
- 0.31 : e145a8: 48 89 d9 mov %rbx,%rcx ▒
- 0.02 : e145ab: 48 0f bf 14 50 movswq (%rax,%rdx,2),%rdx ▒
- 12.19 : e145b0: 49 8b 40 08 mov 0x8(%r8),%rax ▒
- 0.01 : e145b4: 44 0f bf 0c 50 movswl (%rax,%rdx,2),%r9d ▒
- 18.52 : e145b9: 48 8b 87 a8 02 00 00 mov 0x2a8(%rdi),%rax ▒
- 0.00 : e145c0: 4c 89 d7 mov %r10,%rdi ▒
- 0.01 : e145c3: 8b 90 fc 4e 00 00 mov 0x4efc(%rax),%edx
- 0.00 : e145c9: 48 8b 45 28 mov 0x28(%rbp),%rax
再次運(yùn)行“perf record;perf report”,之前的兩個(gè)熱點(diǎn)函數(shù)消耗的CPU也有所下降,
- 56.06% s_dataserver s_dataserver [.] decompress__xxx_by_xxx
- |
- --- decompress__xxx_by_xxx
- |
- |--99.38%-- decompress_xxx_by_yyy
- | …
- 7.69% s_dataserver s_dataserver [.] decompress_xxx_by_yyy
再次運(yùn)行“perf stat”,也有不少有意思的發(fā)現(xiàn),
- stalled CPU cycles大幅減少,說(shuō)明CPU得到了有效利用。
- L1-dcache-loads大幅增加,說(shuō)明更多數(shù)據(jù)從延遲較低的L1 cache讀取。
- LLC-loads大幅減少,說(shuō)明更少數(shù)據(jù)從延遲相對(duì)較高的L3 cache讀取。
- 246476.028262 task-clock # 4.929 CPUs utilized
- 805969061791 cycles # 3.270 GHz [36.37%]
- 177046399865 stalled-cycles-frontend # 21.97% frontend cycles idle [36.42%]
- 97824957888 stalled-cycles-backend # 12.14% backend cycles idle [36.44%]
- 171988020 cache-misses # 0.698 M/sec [36.45%]
- 495575868789 L1-dcache-loads
- # 2010.645 M/sec [36.42%]
- 647748719 L1-dcache-misses
- # 0.13% of all L1-dcache hits [36.38%]
- 192157290531 L1-dcache-stores
- # 779.619 M/sec [36.37%]
- 289881614 L1-dcache-misses
- # 1.176 M/sec [36.36%]
- <not counted> L1-dcache-prefetches
- 862945820 L1-dcache-misses
- # 3.501 M/sec [36.33%]
- 231608715 LLC-loads
- # 0.940 M/sec [36.33%]
- 124342470 LLC-misses
- # 53.69% of all LL-cache hits [36.33%]
- 50.001319609 seconds time elapsed
結(jié)束語(yǔ)
系統(tǒng)性能優(yōu)化是個(gè)非常有挑戰(zhàn)性的工作,是對(duì)一個(gè)人的全面考驗(yàn),包括合適工具的使用,代碼的熟悉程度,分析問(wèn)題的能力,知識(shí)的廣度,還有豐富的想象力,但同時(shí)也是個(gè)非常有意思的經(jīng)歷,你將深刻認(rèn)識(shí)到細(xì)節(jié)的重要性,親身感受到小小優(yōu)化帶來(lái)的大幅性能提升。編輯于 2019-03-15