AMD Zen 3 與 Zen 4 上 FSRM (Fast Short REP MOV) 的效能問題

前幾天 Hacker News 上討論到的一篇:「Rust std fs slower than Python? No, it's hardware (xuanwo.io)」,原文則是在「Rust std fs slower than Python!? No, it's hardware!」。

原因是作者收到回報,提到一段 Rust 寫的 code (在文章裡面的 read_file_with_opendal(),透過 OpenDAL 去讀) 比 Python 的 code 還慢 (在文章裡面的 read_file_with_normal(),直接用 Python 的 open() 開然後讀取)。

先講最後發現問題是 Zen 3 (桌機版 5 系列的 CPU) 與 Zen 4 (桌機版 7 系列的 CPU) 這兩個架構上 REP MOV 系列的指令在某些情境下 (與 offset 有關) 有效能上的問題。

FSRM 類的指令被用在 memcpy()memmove() 類的地方,算是很常見備用到的功能,這次追蹤的問題發現在 glibc 裡面用到導致效能異常。

另外也可以查到在 Linux kernel 裡面也有用到:「Linux 5.6 To Make Use Of Intel Ice Lake's Fast Short REP MOV For Faster memmove()」,所以後續應該也會有些改善的討論...

Ubuntu 這邊的 issue ticket 開在「Terrible memcpy performance on Zen 3 when using rep movsb」這,上游的 glibc 也有對應的追蹤:「30995 – Zen 4: sub-optimal memcpy on very large copies」。

從作者私下得知的消息,因為 patch space 的大小限制,AMD 可能無法提供 CPU microcode 上的 patch,直接解決問題:

However, unverified sources suggest that a fix via amd-ucode is unlikely (at least for Zen 3) due to limited patch space. If you have more information on this matter, please reach out to me.

所以目前比較可行的作法是在 glibc 裡面使用到 FSRM 的地方針對 Zen 3 與 Zen 4 放 workaround,回到原來沒有 FSRM 的方式處理:

Our only hope is to address this issue in glibc by disabling FSRM as necessary. Progress has been made on the glibc front: x86: Improve ERMS usage on Zen3. Stay tuned for updates.

另外在追蹤問題的過程遇到不同的情境,得拿出不同的 profiling 工具出來用,所以也還蠻值得看過一次有個印象:

一開始的 timeit 算是 Python 裡面簡單的 benchmark library:

接著的比較是用 command line 的工具 hyperfine 產生出來的 (給兩個 command 讓他跑),查了一下發現在 Ubuntu 官方的 apt repository 裡面有包進去 (22.04+):

再來是用 strace 追問題,這個算是經典工具了,可以拿來看 syscall 被呼叫的時間點:

到後面出現了 perf 可以拿來看更底層的資訊,像是 CPU 內 cache 的情況:

接續提到的「hotspot ASM」應該也還是 perf 輸出的格式,不過不是那麼確定... 在「perf Examples」這邊可以看到 function 的分析:

而文章裡的則是可以看到已經到 assembly 層級了:

差不多就這些...

改善 Wikipedia 的 JavaScript,減少 300ms 的 blocking time

Hacker News 首頁上看到「300ms Faster: Reducing Wikipedia's Total Blocking Time」這篇,作者 Nicholas RayWikimedia Foundation 的工程師,雖然是貼在自己的 blog 上,但算是半官方性質了... 文章裡面提到了兩個改善都是跟前端 JavaScript 有關的。

作者是透過瀏覽器端的 profiling 產生火焰圖,判讀裡面哪塊是大塊的問題,然後看看有沒有機會改善。

先看最後的成果,可以看到第一個 fix 讓 blocking time 少了 200ms 左右,第二個 fix 則是少了 80ms 左右:

第一個改善是從火焰圖發現 l._enable 吃掉很多 blocking time:

作者發現是因為 find() 找出所有的連結後 (a 元素),跑去每一個連結上面綁定事件造成的效能問題:

The .on("click") call attached a click event listener to nearly every link in the content so that the corresponding section would open if the clicked link contained a hash fragment. For short articles with few links, the performance impact was negligible. But long articles like ”United States” included over 4,000 links, leading to over 200ms of execution time on low-end devices.

但這其實是 redundant code,在其他地方已經有處理了,所以解法就比較簡單,拔掉後直接少了 200ms:

Worse yet, this behavior was unnecessary. The downstream code that listened to the hashchange event already called the same method that the click event listener called. Unless the window’s location already pointed at the link’s destination, clicking a link called the checkHash method twice — once for the link click event handler and once more for the hashchange handler.

第二個改善是 initMediaViewer 吃掉的 blocking time,從 code 也可以看到問題也類似,跑一個 loop 把事件掛到所有符合條件的元素上面:

這邊的解法是 event delegation,把事件掛到上層的元素,就只需要掛一個,然後多加上檢查事件觸發的起點是不是符合條件就可以了,這樣可以大幅降低「掛」事件的成本。

這點算是常用技巧,像是 table 裡面有事件要掛到很多個 td 的時候,會改成把一個事件掛到 table 上面,另外加上判斷條件。

算是蠻標準的 profiling 過程,直接拉出真實數據來看,然後調有重大影響的部分。

從簡單的 C 語言函式來看現代 Compiler 使用 SIMD 的威力

兩個禮拜前在 Hacker News Daily 上看到這篇很精彩的問題與分析,裡面展現出了現代 compiler 最佳化的能力,大量使用了 SIMD 來衝效能:「Why does this code execute more slowly after strength-reducing multiplications? (stackoverflow.com)」,原文在 Stack Overflow 上:「Why does this code execute more slowly after strength-reducing multiplications to loop-carried additions?」。

這篇會很長,除了本來 Stack Overflow 上的討論以外,我另外自己測 GCC 9.4.0 不加上 -O、加上 -O-O3,發現這次 Stack Overflow 給的範例剛剛好把這幾個常見的最佳化等級都練出不同結果,算是蠻厲害的題目。

作者一開始是寫了一個很簡單的版本 A,會透過 loop (對 i 進行) 計算 A*i^2 + B*i + C 的值,把結果放到 array 裡面:

double data[LEN];

void compute()
{
    const double A = 1.1, B = 2.2, C = 3.3;

    int i;
    for(i=0; i<LEN; i++) {
        data[i] = A*i*i + B*i + C;
    }
}

透過一些紙本公式計算可以知道,每次遞增的值雖然不是固定值,但也是有規律的:

所以可以改寫成一堆加號的版本 B:

void compute()
{
    const double A = 1.1, B = 2.2, C = 3.3;
    const double A2 = A+A;
    double Z = A+B;
    double Y = C;

    int i;
    for(i=0; i<LEN; i++) {
        data[i] = Y;
        Y += Z;
        Z += A2;
    }
}

理想上版本 A 在 loop 內用到三個乘法與兩個加法,而版本 B 只用到了三個加法,預期版本 B 應該會快不少,但實際上跑出來的結果剛好反過來:版本 B 慢了許多。

作者實際用 objdump 拉出來看,粗粗看下來也會發現版本 A 的指令多很多:

而版本 B 的指令簡單很多:

在討論下面已經有人給出解釋,主要的原因包括了兩個。

首先是現代 CPU 靠著暴力電路解決,乘法速度跟加法其實不像以前差那麼多,可以從 Instruction tables 這邊看到 MUL 類的指令速度雖然不能跟加法相比,但其實不算慢了,反倒是 DIV 整數除法類的指令比較痛。

另外一個原因,如果仔細看作者貼的 screenshot 分析會發現,在版本 A 裡面,一個 loop 其實做了四次 i 的運算 (add rax, 0x20),而版本 B 只做了一個 i 的運算 (add rax, 0x8),這邊 compiler 幫你 unroll 最佳化改用 SIMD 處理掉了。

在 Stack Overflow 的回答裡面,有人給了一段不錯的 code 示意,提到版本 A 其實先被展成像是這樣的程式碼:

int i;
for (i = 0; i < LEN; i += 4) {
    data[i+0] = A*(i+0)*(i+0) + B*(i+0) + C;
    data[i+1] = A*(i+1)*(i+1) + B*(i+1) + C;
    data[i+2] = A*(i+2)*(i+2) + B*(i+2) + C;
    data[i+3] = A*(i+3)*(i+3) + B*(i+3) + C;
}

然後被 SIMD 包起來處理掉了。

我把作者的 code (他有貼在 GitHub Gist 上) 拿下來編,用不同的 -O-O3 測試,然後去讀 assmebly 的部份也可以看到很多有趣的東西...

首先是在 -O3 的情況下 (也就是作者使用的參數),可以看到類似的結果:(我桌機的 CPU 是定速,沒有跑動態調整)

$ repeat 10 ./a
[-] Took: 248830 ns.
[-] Took: 249150 ns.
[-] Took: 248760 ns.
[-] Took: 248730 ns.
[-] Took: 248770 ns.
[-] Took: 248861 ns.
[-] Took: 248760 ns.
[-] Took: 253050 ns.
[-] Took: 248640 ns.
[-] Took: 249211 ns.
$ repeat 10 ./b
[-] Took: 686660 ns.
[-] Took: 696090 ns.
[-] Took: 696310 ns.
[-] Took: 694431 ns.
[-] Took: 691971 ns.
[-] Took: 697690 ns.
[-] Took: 693241 ns.
[-] Took: 692900 ns.
[-] Took: 654751 ns.
[-] Took: 679101 ns.

從版本 A 的 objdump -d -S -M intel a 可以看到作者 screenshot 內也有看的 unroll 與 SSE2 指令集:

13a0:       66 0f 6f c2             movdqa xmm0,xmm2
13a4:       48 83 c0 20             add    rax,0x20
13a8:       66 0f fe d6             paddd  xmm2,xmm6
13ac:       f3 0f e6 f8             cvtdq2pd xmm7,xmm0
13b0:       66 0f 28 cf             movapd xmm1,xmm7
13b4:       66 0f 70 c0 ee          pshufd xmm0,xmm0,0xee
13b9:       66 0f 59 cd             mulpd  xmm1,xmm5
13bd:       f3 0f e6 c0             cvtdq2pd xmm0,xmm0
13c1:       66 0f 59 cf             mulpd  xmm1,xmm7
13c5:       66 0f 59 fc             mulpd  xmm7,xmm4
13c9:       66 0f 58 cf             addpd  xmm1,xmm7
13cd:       66 0f 58 cb             addpd  xmm1,xmm3
13d1:       0f 29 48 e0             movaps XMMWORD PTR [rax-0x20],xmm1
13d5:       66 0f 28 c8             movapd xmm1,xmm0
13d9:       66 0f 59 cd             mulpd  xmm1,xmm5
13dd:       66 0f 59 c8             mulpd  xmm1,xmm0
13e1:       66 0f 59 c4             mulpd  xmm0,xmm4
13e5:       66 0f 58 c1             addpd  xmm0,xmm1
13e9:       66 0f 58 c3             addpd  xmm0,xmm3
13ed:       0f 29 40 f0             movaps XMMWORD PTR [rax-0x10],xmm0
13f1:       48 39 c2                cmp    rdx,rax
13f4:       75 aa                   jne    13a0 <compute+0x40>

而版本 B 的 objdump -d -S -M intel b 也符合作者提到的現象:

1340:       f2 0f 11 08             movsd  QWORD PTR [rax],xmm1
1344:       48 83 c0 08             add    rax,0x8
1348:       f2 0f 58 c8             addsd  xmm1,xmm0
134c:       f2 0f 58 c2             addsd  xmm0,xmm2
1350:       48 39 d0                cmp    rax,rdx
1353:       75 eb                   jne    1340 <compute+0x30>

但把 gcc 改成 -O 後,可以看到版本 A 的速度慢很多,但還是稍微比版本 B 快一些:

$ repeat 10 ./a
[-] Took: 571140 ns.
[-] Took: 570280 ns.
[-] Took: 571271 ns.
[-] Took: 573971 ns.
[-] Took: 571981 ns.
[-] Took: 569650 ns.
[-] Took: 566361 ns.
[-] Took: 571600 ns.
[-] Took: 571330 ns.
[-] Took: 571030 ns.
$ repeat 10 ./b
[-] Took: 697521 ns.
[-] Took: 696961 ns.
[-] Took: 696201 ns.
[-] Took: 694921 ns.
[-] Took: 696930 ns.
[-] Took: 695001 ns.
[-] Took: 701661 ns.
[-] Took: 698100 ns.
[-] Took: 702430 ns.
[-] Took: 702641 ns.

從 objdump 可以看到版本 A 的變化,退化成一次只處理一個,但把所有的數字都用 xmmN 存放計算:

11b1:       66 0f ef c9             pxor   xmm1,xmm1
11b5:       f2 0f 2a c8             cvtsi2sd xmm1,eax
11b9:       66 0f 28 c1             movapd xmm0,xmm1
11bd:       f2 0f 59 c4             mulsd  xmm0,xmm4
11c1:       f2 0f 59 c1             mulsd  xmm0,xmm1
11c5:       f2 0f 59 cb             mulsd  xmm1,xmm3
11c9:       f2 0f 58 c1             addsd  xmm0,xmm1
11cd:       f2 0f 58 c2             addsd  xmm0,xmm2
11d1:       f2 0f 11 04 c2          movsd  QWORD PTR [rdx+rax*8],xmm0
11d6:       48 83 c0 01             add    rax,0x1
11da:       48 3d 40 42 0f 00       cmp    rax,0xf4240
11e0:       75 cf                   jne    11b1 <compute+0x28>

而版本 B 在 -O 的情況下基本上是一樣的東西 (所以速度上差不多):

11b3:       f2 0f 11 08             movsd  QWORD PTR [rax],xmm1
11b7:       f2 0f 58 c8             addsd  xmm1,xmm0
11bb:       f2 0f 58 c2             addsd  xmm0,xmm2
11bf:       48 83 c0 08             add    rax,0x8
11c3:       48 39 d0                cmp    rax,rdx
11c6:       75 eb                   jne    11b3 <compute+0x2a>

再來是拔掉 -O,都不加就會超慢:

$ repeat 10 ./a
[-] Took: 1097091 ns.
[-] Took: 1092941 ns.
[-] Took: 1092501 ns.
[-] Took: 1091991 ns.
[-] Took: 1092441 ns.
[-] Took: 1093970 ns.
[-] Took: 1091341 ns.
[-] Took: 1093931 ns.
[-] Took: 1094111 ns.
[-] Took: 1092231 ns.
$ repeat 10 ./b
[-] Took: 2703282 ns.
[-] Took: 2705933 ns.
[-] Took: 2703582 ns.
[-] Took: 2702622 ns.
[-] Took: 2703043 ns.
[-] Took: 2702262 ns.
[-] Took: 2703352 ns.
[-] Took: 2703532 ns.
[-] Took: 2703112 ns.
[-] Took: 2702533 ns.

看 objdump 就可以發現幾乎都是對記憶體操作,沒有放到 register 裡面,這是版本 A:

11c1:       f2 0f 2a 45 e4          cvtsi2sd xmm0,DWORD PTR [rbp-0x1c]
11c6:       66 0f 28 c8             movapd xmm1,xmm0
11ca:       f2 0f 59 4d e8          mulsd  xmm1,QWORD PTR [rbp-0x18]
11cf:       f2 0f 2a 45 e4          cvtsi2sd xmm0,DWORD PTR [rbp-0x1c]
11d4:       f2 0f 59 c8             mulsd  xmm1,xmm0
11d8:       f2 0f 2a 45 e4          cvtsi2sd xmm0,DWORD PTR [rbp-0x1c]
11dd:       f2 0f 59 45 f0          mulsd  xmm0,QWORD PTR [rbp-0x10]
11e2:       f2 0f 58 c1             addsd  xmm0,xmm1
11e6:       f2 0f 58 45 f8          addsd  xmm0,QWORD PTR [rbp-0x8]
11eb:       8b 45 e4                mov    eax,DWORD PTR [rbp-0x1c]
11ee:       48 98                   cdqe   
11f0:       48 8d 14 c5 00 00 00    lea    rdx,[rax*8+0x0]
11f7:       00 
11f8:       48 8d 05 41 2e 00 00    lea    rax,[rip+0x2e41]
11ff:       f2 0f 11 04 02          movsd  QWORD PTR [rdx+rax*1],xmm0
1204:       83 45 e4 01             add    DWORD PTR [rbp-0x1c],0x1
1208:       81 7d e4 3f 42 0f 00    cmp    DWORD PTR [rbp-0x1c],0xf423f
120f:       7e b0                   jle    11c1 <compute+0x38>

這是版本 B:

11e8:       8b 45 cc                mov    eax,DWORD PTR [rbp-0x34]
11eb:       48 98                   cdqe   
11ed:       48 8d 14 c5 00 00 00    lea    rdx,[rax*8+0x0]
11f4:       00 
11f5:       48 8d 05 44 2e 00 00    lea    rax,[rip+0x2e44]
11fc:       f2 0f 10 45 d8          movsd  xmm0,QWORD PTR [rbp-0x28]
1201:       f2 0f 11 04 02          movsd  QWORD PTR [rdx+rax*1],xmm0
1206:       f2 0f 10 45 d8          movsd  xmm0,QWORD PTR [rbp-0x28]
120b:       f2 0f 58 45 d0          addsd  xmm0,QWORD PTR [rbp-0x30]
1210:       f2 0f 11 45 d8          movsd  QWORD PTR [rbp-0x28],xmm0
1215:       f2 0f 10 45 d0          movsd  xmm0,QWORD PTR [rbp-0x30]
121a:       f2 0f 58 45 f8          addsd  xmm0,QWORD PTR [rbp-0x8]
121f:       f2 0f 11 45 d0          movsd  QWORD PTR [rbp-0x30],xmm0
1224:       83 45 cc 01             add    DWORD PTR [rbp-0x34],0x1
1228:       81 7d cc 3f 42 0f 00    cmp    DWORD PTR [rbp-0x34],0xf423f
122f:       7e b7                   jle    11e8 <compute+0x5f>

寫到這邊差不多了,作者拿的這個範例算是很有趣的例子,尤其是現代 compiler 幫我們做了超多事情後,很多自己以為的 optimization 其實未必比較好,還是要有個 profiling review 才準...

畫 Python 下記憶體使用情況的 Flamegraph:Memray

前幾天的 Hacker News Daily 上看到的東西,是由 Bloomberg 開發出來的工具 Memray,這個工具是一個 Python 套件:

Memray is a memory profiler for Python. It can track memory allocations in Python code, in native extension modules, and in the Python interpreter itself.

套件有多種輸出,其中一種是可以產生出記憶體使用情況的 flamegraph,轉成圖檔後像是這樣:

官方支援 Python 3.7+:

Memray requires Python 3.7+ and can be easily installed using most common Python packaging tools.

用法看起來也很簡單,之後如果有需要看 memory footprint 的情況好像可以拿來用看看...

Mac 上 sprintf 的 scalability 問題

Hacker News 上看到個有趣的 scalability 問題,在 Mac 上的 sprintf() 因為有 lock 造成的 scalability 問題:「Curious lack of sprintf scaling (aras-p.info)」。

作者注意到 Mac 在多 CPU 下 sprintf() 會有 scalability 的問題,要注意到這邊的 Y 軸是對數比例:

用了 std::stringstream << 反而更慢 (作者還酸了一句「Zero cost abstractions」):

然後用了 Instruments 跑 profiling 找問題,可以看到看起來跟 locale 有關:

一般的情況下應該不會是問題,但如果是需要大量 sprintf() 組字串的人就會比較要注意了。

在「What else can we do?」這段有提到一些解法,包括了 stb_sprintf 當作替代品,以及 {fmt} 作為 iostreams 的替代品,然後另外是利用 to_chars 來解決,如果只是要把數字轉成字串。

算是蠻有趣的 bug hunting 過程,對於開發者來說,一般性的重點還是在 profiling,找到對的問題然後再往下提出解法...

Brendan Gregg 的工具與 profiling 技巧

這篇放在 browser tab 上一陣子了,今天找機會玩一下... 這是 Brendan Gregg 的工具,以及他說明怎麼用他來 profiling:「Analyzing a High Rate of Paging」。

裡面提到的 iostatfree 算是基本盤了,但裡面提到了很多看起來很神奇的東西,像是 biolatency、bitesize、cachestat,可以裝 bpfcc-tools 來用,檔名會加上 -bpfcc 的 suffix (像是 biolatency-bpfcc 這樣)。

三隻程式都需要 root 才能跑,對我來說,在 database 上面分析效能應該是很好用... 好像可以考慮直接當作預設安裝裝到每台機器上?

MIT 的「The Missing Semester of Your CS Education」

MIT 推出的短期課程,在 CS 相關科系裡面不會教,但是如果學過的話會讓你的 CS 學習過程有很不一樣的改變:「The Missing Semester of Your CS Education」。

整個主軸是偏應用為主,其中花了很多篇章在講 CLI 下的工具,這點從每堂課的標題就可以看出來:

1/13: Course overview + the shell
1/14: Shell Tools and Scripting
1/15: Editors (Vim)
1/16: Data Wrangling
1/21: Command-line Environment
1/22: Version Control (Git)
1/23: Debugging and Profiling
1/27: Metaprogramming
1/28: Security and Cryptography
1/29: Potpourri
1/30: Q&A

我自己快速讀過去的時候發現,雖然這是入門課程,但我還是從裡面抓到了一些以前沒有關注的關鍵字 (像是 Python debugger pdb 與 profiling 相關的操作)。

接下來應該會開個連載來寫一下心得與感想...

Vim 的 Performance Profiling

在「Profiling Vim」這邊看到 Vim 上常見的效能問題,很多時候會覺得「慢」但不知道慢在哪邊的問題...

文章作者已經知道是開 Markdown 檔案時的問題,所以可以在開啟 Vim 後用下指令啟動 profiling,但如果是想要追蹤一開起來很慢的問題,可以看「對 Vim 啟動過程做效能分析」這篇的方式,直接在啟動時加上 --startuptime vim.log 這樣的語法,把 log 寫到 vim.log 裡面。

用 Py-Spy 分析 Python 程式效率

這之後應該會變成 Python community 的神器之一...

剛剛看到分析 Python 程式效率的工具,只要有 pid 或是直接包著跑就可以分析:「Py-Spy: A sampling profiler for Python programs.」,執行起來長這樣:

而且還可以直接產生火焰圖讓開發者直接確認,超友善:

在 FAQ 的地方也有提到作者開發這套軟體的原因。有些在開發環境根本看不出問題的,可以很快的透過這個工具在 production 上看:

This project aims to let you profile and debug any running Python program, even if the program is serving production traffic.

另外一個重點在於其他常見的 profiling 工具通常都要改程式引用進來使用,這通常會使得程式效率慢下來,而 Pyflame 支援的平台比較少:

While there are many other python profiling projects, almost all of them require modifying the profiled program in some way. Usually, the profiling code runs inside of the target python process, which will slow down and change how the program operates. This means it's not generally safe to use these profilers for debugging issues in production services since they will usually have a noticeable impact on performance. The only other Python profiler that runs totally in a separate process is pyflame, which profiles remote python processes by using the ptrace system call. While pyflame is a great project, it doesn't support Python 3.7 yet and doesn't work on OSX or Windows.

即將出版的 Xdebug 2.6 能觀察 PHP 的 GC 情況了

在「» Feature: Garbage Collection Statistics」這邊看到 Xdebug 2.6 將能夠收集 PHP 的 GC (garbage collection) 行為了:

Xdebug's built-in garbage collection statistics profiler allows you to find out when the PHP internal garbage collector triggers, how many variables it was able to clean up, how long it took, and how how much memory was actually freed.

這樣 profiling 看的東西就更準確了...