xfs logdev 完美解決cgroup iops限制時ext4 data=writeback才能解決的問題

https://github.com/digoal/blog/blob/master/201601/20160107_02.md
作者

digoal

日期

2016-01-07

標籤

PostgreSQL , xfs , ext4 , cgroup , iops , iohang , writeback , ordered , xfs logdev

背景

Linux下面ext4和xfs都是帶journal的檔案系統，在寫metadata前，必須先寫metadata的journal。

（journal類似資料庫的REDO LOG，可用於災難恢複）

metadata則包含了檔案系統的inodes, directories, indirect blocks資訊。建立檔案（含目錄），改變檔案大小，改變檔案修改時間都涉及metadata的寫操作。

在ext4,xfs檔案系統中，metadata的journal操作是串列的，這點和redo log也類似。

cgroup的blkio模組，可以控制進程對指定塊裝置的讀，寫IOPS，吞吐率等。

當我們對iops進行限制時，由於”metadata的journal操作是串列的”，可能遇到相互幹擾的問題。

例如：

有1個塊裝置，找到它的major,minor號。

#ll /dev/mapper/aliflash-lv0*  lrwxrwxrwx 1 root root 7 Jan  7 11:12 /dev/mapper/aliflash-lv01 -> ../dm-0  #ll /dev/dm-0  brw-rw---- 1 root disk 253, 0 Jan  7 11:22 /dev/dm-0  

在這個塊裝置上建立xfs或ext4檔案系統，並掛載到/data01。

初始化兩個PostgreSQL資料庫執行個體，分別放在/data01不同目錄中。

限制其中一個PostgreSQL叢集對（253:0）這個塊裝置的寫IOPS到100。

ps -ewf|grep postgres  digoal 24259     1  0 12:58 pts/4    00:00:00 /home/digoal/pgsql9.5/bin/postgres  -- 監聽1921  digoal 24260 24259  0 12:58 ?        00:00:00 postgres: logger process              digoal 24262 24259  0 12:58 ?        00:00:00 postgres: checkpointer process        digoal 24263 24259  0 12:58 ?        00:00:00 postgres: writer process              digoal 24264 24259  0 12:58 ?        00:00:00 postgres: wal writer process          digoal 24265 24259  0 12:58 ?        00:00:00 postgres: autovacuum launcher process     digoal 24266 24259  0 12:58 ?        00:00:00 postgres: stats collector process     digoal 24293     1  0 12:58 pts/4    00:00:00 /home/digoal/pgsql9.5/bin/postgres -D /data01/digoal/pg_root  -- 監聽1922  digoal 24294 24293  0 12:58 ?        00:00:00 postgres: logger process                                          digoal 24296 24293  0 12:58 ?        00:00:20 postgres: checkpointer process                                    digoal 24297 24293  0 12:58 ?        00:00:00 postgres: writer process                                          digoal 24298 24293  0 12:58 ?        00:00:00 postgres: wal writer process                                      digoal 24299 24293  0 12:58 ?        00:00:00 postgres: autovacuum launcher process                             digoal 24300 24293  0 12:58 ?        00:00:00 postgres: stats collector process   

限制1921執行個體的IOPS

cd /sys/fs/cgroup/blkio/  mkdir cg1  cd cg1  echo "253:0 100" > blkio.throttle.write_iops_device  echo 24259 > tasks  echo 24260 > tasks  echo 24262 > tasks  echo 24263 > tasks  echo 24264 > tasks  echo 24265 > tasks  echo 24266 > tasks 

開啟一個會大量修改metadata的壓測。使用create database即可。

（create database會大量的COPY模板庫的資料檔案，調用fsync。從而產生大量的metadata修改的動作，觸發metadata journal的修改。）

vi test.sh  #!/bin/bash  for ((i=0;i<100;i++))  do  psql -h 127.0.0.1 -p 1921 -c "create database $i"  done  . ./test.sh  

觀察塊裝置IOPS，被寫IOPS限制在100了。

iostat -x 1  avg-cpu:  %user   %nice %system %iowait  %steal   %idle             0.00    0.00    0.03    3.12    0.00   96.84  Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await  svctm  %util  dm-0              0.00     0.00    0.00  100.00     0.00  1600.00    16.00     0.00    0.00   0.00   0.00  

現在連到1922的執行個體，去壓測效能:

pgbench -i -s 100 -h 127.0.0.1 -p 1922  pgbench -M prepared -n -r -P 1 -c 96 -j 96 -T 100 -h 127.0.0.1 -p 1922  progress: 1.0 s, 33.0 tps, lat 2.841 ms stddev 1.746  progress: 2.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 3.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 4.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 5.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 6.0 s, 197.2 tps, lat 2884.437 ms stddev 2944.982  progress: 7.0 s, 556.6 tps, lat 33.527 ms stddev 34.798  progress: 8.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 9.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 10.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 11.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 12.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 13.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 14.0 s, 0.0 tps, lat -nan ms stddev -nan  progress: 15.0 s, 0.0 tps, lat -nan ms stddev -nan  

可以看到，1922的效能受到了1921的影響，實際上塊裝置的IO能力有幾十萬。

為什麼。

由於metadata journal是串列操作的，當1921執行個體操作metadata journal變慢之後，影響了1922執行個體對該檔案系統的metadata journal的操作。

甚至select 1;這種操作都會受到影響，原因是每次front process與PostgreSQL在建立串連時，需要建立一個臨時catalog檔案global/pg_internal.init.pid。

跟蹤第二個資料庫執行個體的postmaster進程

[root@digoal ~]# strace -T -f -p 24293 >./conn 2>&1  

串連第二個資料庫執行個體

postgres@digoal-> strace -T psql -h 127.0.0.1 -p 1922  execve("/opt/pgsql/bin/psql", ["psql", "-h", "127.0.0.1", "-p", "1922"], [/* 34 vars */]) = 0 <0.009976>  brk(0)                                  = 0x1747000 <0.000007>  

…
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) // 會卡在這裡
此時在系統中可以看到startup進程，是postmaster fork出來的，注意這個進程號，和後面的conn檔案對應起來。

[root@digoal postgresql-9.4.4]# ps -efw|grep start  postgres 46147 24293  0 19:43 ?        00:00:00 postgres: postgres postgres 127.0.0.1(17947) startup  strace -T psql -h 127.0.0.1 -p 1922的輸出截取：  setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 <0.000008>  connect(3, {sa_family=AF_INET, sin_port=htons(1922), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000943>  poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) <0.000011>  getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 <0.000124>  getsockname(3, {sa_family=AF_INET, sin_port=htons(17947), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 <0.000015>  poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) <0.000008>  sendto(3, "\0\0\0\10\4\322\26/", 8, MSG_NOSIGNAL, NULL, 0) = 8 <0.000050>  poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}]) <0.000600>  recvfrom(3, "N", 16384, 0, NULL, NULL)  = 1 <0.000010>  poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}]) <0.000007>  sendto(3, "\0\0\0T\0\3\0\0user\0postgres\0database\0p"..., 84, MSG_NOSIGNAL, NULL, 0) = 84 <0.000020>  

poll回應時間達到了67秒

poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}]) <67.436925>  , 回應時間達到了67秒  recvfrom(3, "R\0\0\0\10\0\0\0\0S\0\0\0\32application_name\0p"..., 16384, 0, NULL, NULL) = 322 <0.000017>  

當建立串連後，查看postmaster進程的跟蹤情況。可以看到startup進程46147，這個進程調用write花了66秒，因為這次調用write時觸發了寫修改metadata的動作。

[root@digoal ~]# grep "pid 46147" conn|less  [pid 46147] mmap(NULL, 528384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f1403d000 <0.000012>  [pid 46147] unlink("global/pg_internal.init.46147") = -1 ENOENT (No such file or directory) <0.000059>  [pid 46147] open("global/pg_internal.init.46147", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 14 <0.000068>  [pid 46147] fstat(14, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0 <0.000013>  [pid 46147] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f1403c000 <0.000020>  [pid 46147] write(14, "f2W\0008\1\0\0\0\0\0\0\200\6\0\0\0\0\0\0U2\0\0\0\0\0\0\0\0\0\0"..., 4096 <unfinished ...>  [pid 46147] <... write resumed> )       = 4096 <66.317440>  [pid 46147] --- SIGALRM (Alarm clock) @ 0 (0) ---  找到對應的代碼：write_relcache_init_file@src/backend/utils/cache/relcache.c

重新跟蹤這個c檔案：

[root@digoal ~]# cat trc.stp   global f_start[999999]  probe process("/opt/pgsql/bin/postgres").function("*@/opt/soft_bak/postgresql-9.4.4/src/backend/utils/cache/relcache.c").call {     f_start[execname(), pid(), tid(), cpu()] = gettimeofday_ms()  }  probe process("/opt/pgsql/bin/postgres").function("*@/opt/soft_bak/postgresql-9.4.4/src/backend/utils/cache/relcache.c").return {     t=gettimeofday_ms()    a=execname()    b=cpu()    c=pid()    d=pp()    e=tid()    if (f_start[a,c,e,b] && t-f_start[a,c,e,b]>1) {  #    printf("time:%d, execname:%s, pp:%s, par:%s\n", t - f_start[a,c,e,b], a, d, $$locals$$)      printf("time:%d, execname:%s, pp:%s\n", t - f_start[a,c,e,b], a, d)    }  }  

因為startup進程是動態產生的，所以只能這樣> [root@digoal ~]# cat t.sh !/bin/bash for ((i=0;i<1;i=0)) do PID=ps -ewf|grep start|grep -v grep|awk '{print $2}' stap -vp 5 -DMAXSKIPPED=9999999 -DSTP_NO_OVERLOAD -DMAXTRYLOCK=100 ./trc.stp -x $PID done 重新跟蹤如下：

postgres@digoal-> strace -T psql -h 127.0.0.1 -p 1922
[root@digoal ~]# . ./t.sh Pass 1: parsed user script and 111 library
script(s) using 209296virt/36828res/3172shr/34516data kb, in
180usr/20sys/199real ms. Pass 2: analyzed script: 102 probe(s), 7
function(s), 4 embed(s), 1 global(s) using
223800virt/51400res/4172shr/49020data kb, in 80usr/60sys/142real ms.
Pass 3: translated to C into
“/tmp/stapbw7MDq/stap_b17f8a3318ccf4b972f4b84491bbdc1e_54060_src.c”
using 223800virt/51744res/4504shr/49020data kb, in 10usr/40sys/57real
ms. Pass 4: compiled C into
“stap_b17f8a3318ccf4b972f4b84491bbdc1e_54060.ko” in
1440usr/370sys/1640real ms. Pass 5: starting run. time:6134,
execname:postgres,
pp:process(“/opt/pgsql9.4.4/bin/postgres”).function(“write_item@/opt/soft_bak/postgresql-9.4.4/src/backend/utils/cache/relcache.c:4979”).return time:3, execname:postgres,
pp:process(“/opt/pgsql9.4.4/bin/postgres”).function(“write_item@/opt/soft_bak/postgresql-9.4.4/src/backend/utils/cache/relcache.c:4979”).return time:6, execname:postgres,
pp:process(“/opt/pgsql9.4.4/bin/postgres”).function(“write_item@/opt/soft_bak/postgresql-9.4.4/src/backend/utils/cache/relcache.c:4979”).return…
以上問題怎麼解決。如何隔離資料庫執行個體的IOPS不會產生相互幹擾呢。

解決辦法1

不同的執行個體使用不同的檔案系統。

例如

mkfs.ext4 /dev/mapper/vgdata01-lv01  mkfs.ext4 /dev/mapper/vgdata01-lv02  mount /dev/mapper/vgdata01-lv01 /data01  mount /dev/mapper/vgdata01-lv02 /data02 

兩個資料庫執行個體分別放在/data01和/data02

限制/dev/mapper/vgdata01-lv01的IOPS，不會影響另一個檔案系統。

這種方法的弊端：如果執行個體數很多，需要拆分成很多個小的檔案系統，不適合空間彈性管理和共用。

解決辦法2

針對ext4

正常情況下寫資料的順序如果你要修改metadata，必須確保metadata對應的塊改變已經落盤，因此可能出現寫metadata被迫要刷dirty data page的情況。

pic

如果dirty data page刷盤很慢，就會導致metadata寫受堵。而寫metadata journal又是串列的，勢必影響其他進程對metadata journal的修改。

使用 data=writeback 載入ext4檔案系統。

這個方法的原理是寫metadata前，不需要等待data寫完。從而可能出現metadata是新的，但是資料是舊的情況。(例如inode是新的，data是舊的，可能某些inode引用的塊不存在或者是舊的已刪除的塊)

寫metadata不等待寫data，好處就是串列操作不好因為data受堵塞而堵塞。

       data={journal|ordered|writeback}                Specifies the journalling mode for file data.  Metadata is always journaled.  To use modes other than ordered on the root filesystem, pass the mode to  the  kernel  as  boot  parameter,  e.g.   root-                flags=data=journal.                journal                       All data is committed into the journal prior to being written into the main filesystem.                ordered                       This is the default mode.  All data is forced directly out to the main file system prior to its metadata being committed to the journal.                writeback                       Data  ordering  is not preserved - data may be written into the main filesystem after its metadata has been committed to the journal.  This is rumoured to be the highest-throughput option.  It                       guarantees internal filesystem integrity, however it can allow old data to appear in files after a crash and journal recovery.  

弊端，檔案系統或作業系統crash後，可能導致metadata和data不一致，出現髒塊。

解決辦法3

將用作journal塊裝置獨立出來，在限制IOPS時，不限制journal塊裝置的IO(因為metadata journal的操作很少，也很快，沒有必要限制)，只限制data塊裝置的IO。

這種方法只適合xfs檔案系統。

ext4檔案系統使用這種方法未達到效果，ext4分開journal dev方法如下，但是沒有效果，你可以嘗試一下。

建立邏輯卷，一個放DATA，一個放journal

#pvcreate /dev/dfa  #pvcreate /dev/dfb  #pvcreate /dev/dfc  #vgcreate aliflash /dev/dfa /dev/dfb /dev/dfc  #lvcreate -i 3 -I 8 -L 1T -n lv01 aliflash  #lvcreate -i 3 -I