Performance

寫入時大型 ext4 分區慢得離譜

  • August 29, 2014

我們有四台相同的 Linux 伺服器,帶有一個大 (5T) 硬碟分區。我們有帶有這個核心的 Scientific Linux:

Linux s3.law.di.unimi.it 2.6.32-358.18.1.el6.x86_64 #1 SMP Tue Aug 27 14:23:09 CDT 2013 x86_64 x86_64 x86_64 GNU/Linux

這些伺服器的配置、安裝等都是相同的。但是,只有一台伺服器在使用 ext4 編寫時速度慢得離譜。如果我做一個

dd if=/dev/zero of=/mnt/big/analysis/test

l -tr
total 11M
-rw-r--r-- 1 root    root  11M Apr 20 10:01 test
10:01:42 [s3] /mnt/big/analysis
l -tr
total 16M
-rw-r--r-- 1 root    root  16M Apr 20 10:02 test
10:02:13 [s3] /mnt/big/analysis

所以 5MB 在 30 年代。所有其他伺服器的寫入速度都快了一個數量級以上。

這些機器是 64GB,32 核,沒有 I/O 或 CPU 活動,儘管 90% 的記憶體被一個大型 Java 程序填滿,什麼都不做。只有台機器寫得很慢。

SMART 說一切正常

# smartctl -H /dev/sdb
smartctl 5.42 2011-10-20 r3458 [x86_64-linux-2.6.32-358.18.1.el6.x86_64] (local build)
Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net

SMART Health Status: OK

hdparm 讀取沒有問題:

# hdparm -t /dev/sdb

/dev/sdb:
Timing buffered disk reads:  1356 MB in  3.00 seconds = 451.60 MB/sec

分區掛載如下:

/dev/sdb1 on /mnt/big type ext4 (rw,noatime,data=writeback)

我們設置

tune2fs -o journal_data_writeback /dev/sdb1

為了表現。

我試圖找到任何可以解釋為什麼這個特定的伺服器寫得這麼慢的東西,也就是說,診斷工具的輸出有什麼不同,但沒有結果。

只是為了完成圖片:我們開始在所有伺服器上爬行,分區基本上是空的。爬網在分區上創建了許多文件,特別是一個 156G 的文件(爬網的儲存)。爬網開始正常,但幾個小時後我們看到速度變慢(顯然,隨著商店的增長)。當我們檢查時,我們注意到寫入磁碟的速度越來越慢,越來越慢,越來越慢。

我們停止了一切——沒有 CPU 活動,沒有 I/O——但 dd 仍然顯示上述行為。其他三台伺服器,在相同的條件下,相同的文件等,在爬網期間和使用 dd 時都可以正常工作。

坦率地說,我什至不知道在哪裡看。有人聽到鈴聲嗎?我可以使用哪些診斷工具來了解正在發生的事情,或者我應該嘗試哪些測試?

更新

除了發布的連結之外,我認為在執行爬蟲的兩台伺服器上執行相同的測試是個好主意。這真有趣。例如, vmstat 10 給出

好的

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
4  0  68692 9009864  70832 29853400    0    0    15   214    9    2 11  1 88  0  0 
10  0  68692 8985620  70824 29883460    0    0    48  7402 79465 62898 12  1 86  0  0   
11  0  68692 8936780  70824 29928696    0    0    54  6842 81500 66665 15  1 83  0  0   
10  2  68692 8867280  70840 30000104    0    0    65 36578 80252 66272 14  1 85  0  0   
15  0  68692 8842960  70840 30026724    0    0    61  3667 81245 65161 14  1 85  0  0   

壞的

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
13  0   8840 14015100  92972 25683108    0    0    11   104    3    9  4  1 94  0  0    
2  0   8840 14015800  92984 25696108    0    0    49 16835 38619 54204  2  2 96  0  0  
1  0   8840 14026004  93004 25699940    0    0    33  4152 25914 43530  0  2 98  0  0  
1  0   8840 14032272  93012 25703716    0    0    30  1164 25062 43230  0  2 98  0  0  
2  0   8840 14029632  93020 25709448    0    0    24  5619 23475 40080  0  2 98  0  0  

和 iostat -x -k 5

好的

Linux 2.6.32-358.18.1.el6.x86_64 (s0.law.di.unimi.it)   04/21/2014  _x86_64_    (64 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
         10.65    0.00    1.02    0.11    0.00   88.22

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sdb               0.11  3338.25   17.98   56.52   903.55 13579.19   388.79     7.32   98.30   1.23   9.18
sda               0.39     0.72    0.49    0.76    11.68     5.90    28.25     0.01   11.25   3.41   0.43

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
         15.86    0.00    1.33    0.03    0.00   82.78

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sdb               0.00  1106.20    9.20   31.00    36.80  4549.60   228.18     0.41   10.09   0.39   1.58
sda               0.00     2.20    0.80    3.00     4.80    20.80    13.47     0.04   10.53   3.21   1.22

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
         15.42    0.00    1.23    0.01    0.00   83.34

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sdb               0.00  1205.40    8.00   33.60    40.80  4956.00   240.23     0.39    9.43   0.33   1.38
sda               0.00     0.60    0.00    1.00     0.00     6.40    12.80     0.01    5.20   4.20   0.42

壞的

Linux 2.6.32-358.18.1.el6.x86_64 (s2.law.di.unimi.it)   04/21/2014  _x86_64_    (64 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          4.37    0.00    1.41    0.06    0.00   94.16

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sdb               0.06  1599.70   13.76   38.23   699.27  6551.73   278.96     3.12   59.96   0.99   5.16
sda               0.46     3.17    1.07    0.78    22.51    15.85    41.26     0.03   16.10   2.70   0.50

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
         11.93    0.00    2.99    0.60    0.00   84.48

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sdb               0.00 14885.40   13.60  141.20    54.40 60106.40   777.27    34.90  225.45   1.95  30.14
sda               0.00     0.40    0.00    0.80     0.00     4.80    12.00     0.01    7.00   3.25   0.26

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
         11.61    0.00    2.51    0.16    0.00   85.71

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sdb               0.00  2245.40   10.60   51.20    42.40  9187.20   298.69     3.51   56.80   2.04  12.58
sda               0.00     0.40    0.00    0.80     0.00     4.80    12.00     0.01    6.25   3.25   0.26

所以(如果我對輸出的理解正確的話)看起來,是的,從 JVM 堆棧跟踪中可以明顯看出,慢速伺服器需要永遠進行 I/O。仍有待理解為什麼:(。

我也跑了一個strace -c ls -R /。沒想到要跑一會,所以前面的數據意義不大。該命令是在爬蟲執行時執行的,因此正在進行大量 I/O。

好的

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
99.62   14.344825         114    126027           getdents
 0.25    0.036219           1     61812        12 open
 0.07    0.009891           0     61802           close
 0.06    0.007975           0     61801           fstat
 0.01    0.000775           0      8436           write
 0.00    0.000043          22         2           rt_sigaction
 0.00    0.000000           0        12           read
 0.00    0.000000           0         1           stat
 0.00    0.000000           0         3         1 lstat
 0.00    0.000000           0        33           mmap
 0.00    0.000000           0        16           mprotect
 0.00    0.000000           0         4           munmap
 0.00    0.000000           0        15           brk
 0.00    0.000000           0         1           rt_sigprocmask
 0.00    0.000000           0         3         3 ioctl
 0.00    0.000000           0         1         1 access
 0.00    0.000000           0         3           mremap
 0.00    0.000000           0         1           execve
 0.00    0.000000           0         1           fcntl
 0.00    0.000000           0         1           getrlimit
 0.00    0.000000           0         1           statfs
 0.00    0.000000           0         1           arch_prctl
 0.00    0.000000           0         3         1 futex
 0.00    0.000000           0         1           set_tid_address
 0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00   14.399728                319982        18 total

壞的

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
99.81   24.210936         181    133618           getdents
 0.14    0.032755           1     63183        14 open
 0.03    0.006637           0     63171           close
 0.02    0.005410           0     63170           fstat
 0.00    0.000434           0     15002           write
 0.00    0.000000           0        12           read
 0.00    0.000000           0         1           stat
 0.00    0.000000           0         4         1 lstat
 0.00    0.000000           0        33           mmap
 0.00    0.000000           0        16           mprotect
 0.00    0.000000           0         4           munmap
 0.00    0.000000           0        25           brk
 0.00    0.000000           0         2           rt_sigaction
 0.00    0.000000           0         1           rt_sigprocmask
 0.00    0.000000           0         3         3 ioctl
 0.00    0.000000           0         1         1 access
 0.00    0.000000           0         3           mremap
 0.00    0.000000           0         1           execve
 0.00    0.000000           0         1           fcntl
 0.00    0.000000           0         1           getrlimit
 0.00    0.000000           0         1           statfs
 0.00    0.000000           0         1           arch_prctl
 0.00    0.000000           0         3         1 futex
 0.00    0.000000           0         1           set_tid_address
 0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00   24.256172                338259        20 total

這是核心。我們使用的是相當老的 2.6.32,但它是 Red Hat EL 和 Scientific Linux 支持的版本。

今天我和一位在調整高性能索引算法方面有類似經驗的朋友 ( Giuseppe Ottaviano ) 共進午餐。升級到最新版本後(編譯器、庫等),他將核心更改為 3.10 行,突然一切正常。

它也對我們有用。使用 3.10 核心(由http://elrepo.org提供),所有問題都消失了。

Giuseppe 懷疑 NUMA 和核心分頁之間存在有害的互動,這會導致核心瘋狂地載入和保存相同的數據,從而使機器幾乎停止執行。

引用自:https://unix.stackexchange.com/questions/125677