[pgsql-jp: 38864] HDD差異だけで更新性能だけこんなに違うのはなぜ？
omi ＠ ydc.co.jp
omi ＠ ydc.co.jp
2007年 10月 18日 (木) 20:56:17 JST
なごやの尾見です。
初投稿ですが、よろしくお願いします。
DBクラスタを置くHDDの違いによって、postgreの更新系処理の
性能が著しく異なり、原因の究明に行き詰っています。
問題の切り分けにあたり、アドバイスやヒントをいただけると幸いです。
---
当方の実行環境はRHEL5&postgresql8.1.9で、
・DBクラスタ1: /dev/sda10 （内臓SAS)
・DBクラスタ2: /dev/sde1 (外付けDiskArray)
となっています（詳細の環境は文末）。
・同一マシンでの検証
・両ディスク内で、DBクラスタを置くパーティションは同一サイズ(ext3)
・両者のDBクラスタの内容(/var/lib/pgsql以下相当）は同じ
・従って各種パラメータ(GUC)も全て同じ
という条件で、かつディスクの性能差は大差ないのに、
pgbench(TPC-B)の性能差が１０倍以上となっています。
外付けの方（/dev/sde1）が、このままでは使いものになりません。
# DBは最終的には共有Diskにおかないと意味がないのです。。。
検証時の測定環境やデータについては文末に詳細を書きましたが、
概略、以下のようなことが判っています。
・参照系(SELECT)は全く問題なく、問題は更新系。
・デバイス直のdd書込みでは、性能差はほとんどなし(sda10==sde1)。
・mount後のFileSystem上へのdd書込みでは, sda10が1.5倍強は速い。
・GUCのfsync_methodは全パターン試したが有意差なし
（fsync=offならさすがに改善しますが）。
・PAEカーネルを標準に戻しても結果は同じ。
・大容量メモリを疑ってOSブート時にmem=1Gにしてみても結果は同じ。
・pgbenchで '-c 1'にしても、結果は同じ。
・性能差はpgbenchの結果のみならず、実際のAPの更新処理も同様。
--------
疑わしいと思うのは；
・Postgresqlの問題（使用方法も含め）
・カーネルのドライバの問題（またはファーム）
少々気になっているのは、詳細にあるとおり、
pgbench実施中のtopで確認したプロセスの状態として、
---
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ P WCHAN COMMAND
4695 postgres 16 0 276m 4596 3740 D 0 0.1 0:00.01 2 sync_page postmaster
---
のようなものが、/dev/sde1で検証した場合に大量にあること。
State='D'、WCHAN='sync_page'の状態になってます。
/dev/sda10で検証した場合もあるにはありますが、数は少ないし、
sync_pageだけでなく、blockdev_ を実施中のものも散見されます。
fsync=offだと性能が出ることからも、
postgreバックエンドが実行しようとしているsyncが、
カーネル内でI/O待ちで溜まっているのがいかんのでしょう。
そうすると、後者の「カーネルのドライバの問題（またはファーム）」
も疑わしいのですが、dd書き込みで両ディスクはさほど差がないので、
OS以下の問題でもないような。。。
そもそも、postgreバックエンドがsyncするのと、
プロンプトでsyncコマンドをたたくのには、
カーネル内の処理の仕方に違いがあるのだろうか。
postgreバックエンドもユーザプロセスである以上、
直接ディスクに働きかけているはずはないし。
------------
さて、以下に検証データと環境情報を載せておきます。
# DBクラスタに使用しているパーティションの
# デバイスファイル名がプロンプトになるようにしてあります。
# pgbenchのデータは、 pgbench -i -s 10 bench、で作成したものです。
■DBクラスタが内臓SAS(/dev/sda10)にある場合
sda10# /etc/init.d/postgresql restart
postgresql サービスを停止中: [ OK ]
postgresql サービスを開始中: [ OK ]
sda10# su - postgres -c 'time pgbench -c 16 -t 256 bench'
starting vacuum...end.
transaction type: TPC-B (sort of)
scaling factor: 10
number of clients: 16
number of transactions per client: 256
number of transactions actually processed: 4096/4096
tps = 223.478208 (including connections establishing)
tps = 223.799161 (excluding connections establishing)
mou
real 0m18.397s
user 0m0.119s
sys 0m0.224s
sda10# 上記実行のtopコマンド出力抜粋(Idle Processes toggle off)
top - 18:09:40 up 16 min, 3 users, load average: 0.98, 1.01, 0.64
Tasks: 112 total, 4 running, 108 sleeping, 0 stopped, 0 zombie
Cpu(s): 4.3%us, 1.5%sy, 0.0%ni, 65.1%id, 29.1%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 8309172k total, 477984k used, 7831188k free, 20284k buffers
Swap: 10241312k total, 0k used, 10241312k free, 388540k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ P WCHAN COMMAND
4161 root 15 0 2168 1000 780 R 1 0.0 0:00.03 3 stext top
4210 postgres 16 0 5808 1596 1172 R 2 0.0 0:00.31 2 stext pgbench
4219 postgres 15 0 276m 11m 10m R 1 0.1 0:00.15 2 semtimedo postmaster
4223 postgres 15 0 276m 10m 9.8m R 1 0.1 0:00.15 2 semtimedo postmaster
4214 postgres 15 0 276m 10m 9944 D 2 0.1 0:00.15 0 blockdev_ postmaster
4226 postgres 15 0 276m 10m 9m D 1 0.1 0:00.14 0 sync_page postmaster
top - 18:09:41 up 16 min, 3 users, load average: 0.98, 1.01, 0.64
Tasks: 99 total, 1 running, 98 sleeping, 0 stopped, 0 zombie
Cpu(s): 3.3%us, 3.8%sy, 0.0%ni, 65.9%id, 27.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 8309172k total, 472576k used, 7836596k free, 20300k buffers
Swap: 10241312k total, 0k used, 10241312k free, 391772k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ P WCHAN COMMAND
4161 root 15 0 2168 1000 780 R 0 0.0 0:00.03 3 stext top
4155 postgres 16 0 276m 60m 59m D 9 0.7 0:00.09 2 get_reque postmaster
4225 postgres 16 0 276m 11m 10m D 3 0.1 0:00.15 2 blockdev_ postmaster
sda10# /etc/init.d/postgresql restart
postgresql サービスを停止中: [ OK ]
postgresql サービスを開始中: [ OK ]
sda10# su - postgres -c 'time pgbench -S -c 32 -t 1024 bench'
starting vacuum...end.
transaction type: SELECT only
scaling factor: 10
number of clients: 32
number of transactions per client: 1024
number of transactions actually processed: 32768/32768
tps = 21527.586162 (including connections establishing)
tps = 22263.637395 (excluding connections establishing)
real 0m1.534s
user 0m0.184s
sys 0m0.230s
sda10# hdparm -t -T /dev/sda10
/dev/sda10:
Timing cached reads: 13076 MB in 2.00 seconds = 6545.16 MB/sec
Timing buffered disk reads: 142 MB in 3.02 seconds = 47.03 MB/sec
sda10#
sda10# time ( dd if=/dev/zero of=/DB/BIG bs=1M count=1024 ; sync )
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB) copied, 4.72524 seconds, 227 MB/s
real 0m21.490s
user 0m0.001s
sys 0m1.909s
sda10# time ( dd if=/dev/zero of=/dev/sda10 bs=1M count=1024 ; sync )
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB) copied, 40.8455 seconds, 26.3 MB/s
real 0m40.898s
user 0m0.000s
sys 0m1.463s
■DBクラスタが外付DiskArray(/dev/sde1)にある場合
sde1# /etc/init.d/postgresql restart
postgresql サービスを停止中: [ OK ]
postgresql サービスを開始中: [ OK ]
sde1# su - postgres -c 'time pgbench -c 16 -t 256 bench'
starting vacuum...end.
transaction type: TPC-B (sort of)
scaling factor: 10
number of clients: 16
number of transactions per client: 256
number of transactions actually processed: 4096/4096
tps = 15.657742 (including connections establishing)
tps = 15.659244 (excluding connections establishing)
real 4m21.910s
user 0m0.130s
sys 0m0.320s
★★★ 立派な(?)なハードなのに、これはちょっと ★★★
sde1# 上記実行のtopコマンド出力抜粋(Idle Processes toggle off)
Tasks: 109 total, 1 running, 108 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.3%us, 0.0%sy, 0.0%ni, 49.4%id, 50.4%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 8309172k total, 251108k used, 8058064k free, 19556k buffers
Swap: 10241312k total, 0k used, 10241312k free, 168648k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ P WCHAN COMMAND
4634 root 15 0 2164 1000 784 R 0 0.0 0:00.01 3 stext top
4686 postgres 16 0 276m 4608 3748 D 0 0.1 0:00.00 2 sync_page postmaster
4687 postgres 16 0 276m 4452 3596 D 0 0.1 0:00.01 2 sync_page postmaster
4688 postgres 15 0 276m 4468 3620 D 0 0.1 0:00.00 2 sync_page postmaster
4689 postgres 16 0 276m 4616 3756 D 0 0.1 0:00.01 2 sync_page postmaster
4690 postgres 16 0 276m 4840 3984 D 0 0.1 0:00.00 2 sync_page postmaster
4691 postgres 16 0 276m 4656 3800 D 0 0.1 0:00.01 2 sync_page postmaster
4693 postgres 16 0 276m 4484 3628 D 0 0.1 0:00.01 2 sync_page postmaster
4694 postgres 16 0 276m 4588 3728 D 0 0.1 0:00.01 2 sync_page postmaster
4695 postgres 16 0 276m 4596 3740 D 0 0.1 0:00.01 2 sync_page postmaster
4696 postgres 16 0 276m 4584 3728 D 0 0.1 0:00.01 2 sync_page postmaster
4697 postgres 16 0 276m 4608 3752 D 0 0.1 0:00.01 2 sync_page postmaster
4698 postgres 16 0 276m 4616 3760 D 0 0.1 0:00.00 2 sync_page postmaster
4699 postgres 16 0 276m 4608 3748 D 0 0.1 0:00.01 2 sync_page postmaster
4685 postgres 16 0 276m 4680 3824 D 0 0.1 0:00.00 1 sync_page postmaster
4692 postgres 15 0 276m 4580 3724 D 0 0.1 0:00.01 1 sync_page postmaster
4700 postgres 15 0 276m 4456 3592 D 0 0.1 0:00.00 1 sync_page postmaster
top - 18:15:22 up 21 min, 2 users, load average: 1.28, 0.61, 0.54
Tasks: 109 total, 1 running, 108 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.0%us, 0.0%sy, 0.0%ni, 50.0%id, 50.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 8309172k total, 251108k used, 8058064k free, 19556k buffers
Swap: 10241312k total, 0k used, 10241312k free, 168648k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ P WCHAN COMMAND
4634 root 15 0 2164 1000 784 R 0 0.0 0:00.01 3 stext top
4686 postgres 16 0 276m 4608 3748 D 0 0.1 0:00.00 2 sync_page postmaster
4687 postgres 16 0 276m 4452 3596 D 0 0.1 0:00.01 2 sync_page postmaster
4688 postgres 15 0 276m 4468 3620 D 0 0.1 0:00.00 2 sync_page postmaster
4689 postgres 16 0 276m 4616 3756 D 0 0.1 0:00.01 2 sync_page postmaster
4690 postgres 16 0 276m 4840 3984 D 0 0.1 0:00.00 2 sync_page postmaster
4691 postgres 16 0 276m 4656 3800 D 0 0.1 0:00.01 2 sync_page postmaster
4693 postgres 16 0 276m 4484 3628 D 0 0.1 0:00.01 2 sync_page postmaster
4694 postgres 16 0 276m 4588 3728 D 0 0.1 0:00.01 2 sync_page postmaster
4695 postgres 16 0 276m 4596 3740 D 0 0.1 0:00.01 2 sync_page postmaster
4696 postgres 16 0 276m 4584 3728 D 0 0.1 0:00.01 2 sync_page postmaster
4697 postgres 16 0 276m 4608 3752 D 0 0.1 0:00.01 2 sync_page postmaster
4698 postgres 16 0 276m 4616 3760 D 0 0.1 0:00.00 2 sync_page postmaster
4699 postgres 16 0 276m 4608 3748 D 0 0.1 0:00.01 2 sync_page postmaster
4685 postgres 16 0 276m 4680 3824 D 0 0.1 0:00.00 1 sync_page postmaster
4692 postgres 15 0 276m 4580 3724 D 0 0.1 0:00.01 1 sync_page postmaster
sde1# /etc/init.d/postgresql restart
postgresql サービスを停止中: [ OK ]
postgresql サービスを開始中: [ OK ]
sde1# su - postgres -c 'time pgbench -S -c 32 -t 1024 bench'
starting vacuum...end.
transaction type: SELECT only
scaling factor: 10
number of clients: 32
number of transactions per client: 1024
number of transactions actually processed: 32768/32768
tps = 22199.639581 (including connections establishing)
tps = 23029.899230 (excluding connections establishing)
sde1# hdparm -t -T /dev/sde1
/dev/sde1:
Timing cached reads: 13144 MB in 2.00 seconds = 6578.23 MB/sec
Timing buffered disk reads: 270 MB in 3.00 seconds = 89.97 MB/sec
sde1# time ( dd if=/dev/zero of=/DB/BIG bs=1M count=1024 ; sync )
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB) copied, 3.90016 seconds, 275 MB/s
real 0m37.200s
user 0m0.002s
sys 0m2.079s
sde1# time ( dd if=/dev/zero of=/dev/sde1 bs=1M count=1024 ; sync )
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB) copied, 40.7442 seconds, 26.4 MB/s
real 0m40.823s
user 0m0.002s
sys 0m1.476s
■実行環境情報
# uname -a
Linux needswebb 2.6.18-8.1.14.el5PAE #1 SMP Tue Sep 25 11:59:13 EDT 2007 i686 i686 i386 GNU/Linux
# rpm -qa | grep postgresql
postgresql-8.1.9-1.el5
postgresql-odbc-08.01.0200-3.1
postgresql-pl-8.1.9-1.el5
postgresql-jdbc-8.1.407-1jpp.4
postgresql-test-8.1.9-1.el5
postgresql-python-8.1.9-1.el5
postgresql-docs-8.1.9-1.el5
postgresql-libs-8.1.9-1.el5
postgresql-server-8.1.9-1.el5
postgresql-contrib-8.1.9-1.el5
#dmesg（抜粋）
scsi0 : LSI Logic SAS based MegaRAID driver
Vendor: FUJITSU Model: MAX3073RC Rev: 2102
Type: Direct-Access ANSI SCSI revision: 03
Vendor: FUJITSU Model: MAX3073RC Rev: 2102
Type: Direct-Access ANSI SCSI revision: 03
Vendor: FUJITSU Model: MAX3073RC Rev: 2102
Type: Direct-Access ANSI SCSI revision: 03
Vendor: LSI Model: MegaRAID SAS RMB Rev: 1.03
Type: Direct-Access ANSI SCSI revision: 05
SCSI device sda: 142278656 512-byte hdwr sectors (72847 MB)
sda: Write Protect is off
sda: Mode Sense: 1f 00 00 08
SCSI device sda: drive cache: write back, no read (daft)
SCSI device sda: 142278656 512-byte hdwr sectors (72847 MB)
sda: Write Protect is off
sda: Mode Sense: 1f 00 00 08
SCSI device sda: drive cache: write back, no read (daft)
sda: sda1 sda2 sda3 sda4 < sda5 sda6 sda7 sda8 sda9 sda10 >
sd 0:2:0:0: Attached scsi disk sda
Fusion MPT SAS Host driver 3.04.02
ACPI: PCI Interrupt 0000:08:00.0[A] -> GSI 16 (level, low) -> IRQ 169
mptbase: Initiating ioc0 bringup
ioc0: SAS1068E: Capabilities={Initiator}
PCI: Setting latency timer of device 0000:08:00.0 to 64
scsi1 : ioc0: LSISAS1068E, FwRev=01120000h, Ports=1, MaxQ=511, IRQ=169
Vendor: XYRATEX Model: E5402E Rev:
Type: Direct-Access ANSI SCSI revision: 04
SCSI device sde: 39075840 512-byte hdwr sectors (20007 MB)
sde: Write Protect is off
sde: Mode Sense: a7 00 10 08
SCSI device sde: drive cache: write back w/ FUA
SCSI device sde: 39075840 512-byte hdwr sectors (20007 MB)
sde: Write Protect is off
sde: Mode Sense: a7 00 10 08
SCSI device sde: drive cache: write back w/ FUA
sde: sde1
sd 1:0:0:3: Attached scsi disk sde
# インストール後に変更したGUC
max_connections = 256
shared_buffers = 32768 # min 16 or max_connections*2, 8KB each
temp_buffers = 8192 # min 100, 8KB each
work_mem = 8192 # min 64, size in KB
max_fsm_pages = 89600 # min max_fsm_relations*16, 6 bytes each
wal_sync_method = open_sync # the default is the first option
wal_buffers = 32 # min 4, 8KB each
effective_cache_size = 32768 # typically 8KB each
# チューニングの余地はまだだあると思うが、
# 両ＤＢクラスタとも、同じ値を使って検証しているのは間違いないです。
以上です。
pgsql-jp メーリングリストの案内