* Investigate on r4 iozone/sql-bench performance bottleneck: stage one
@ 2007-02-06 8:37 Xu CanHao
[not found] ` <6ec7a4340702062302t24d0fa3bv9c17e9b89e1d9f00@mail.gmail.com>
0 siblings, 1 reply; 2+ messages in thread
From: Xu CanHao @ 2007-02-06 8:37 UTC (permalink / raw)
To: Vladimir V. Saveliev, reiserfs-list
Hi!
I've made an analysis of r4 performance bottleneck on sql-bench/iozone
recently, and here is the conclusion:
1, default iozone benchmarks(-Ra) only involves
read()/write()/fread()/fwrite()...etc, although many fsync() during
iozone, the fsync() time is not calculated in the result, the function
invocation pattern is like(iozone -s 4K -r 1K):
gettimeofday({1170749541, 313179}, NULL) = 0 <0.000015>
write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000174>
write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000060>
write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000057>
write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000094>
gettimeofday({1170749541, 313904}, NULL) = 0 <0.000008>
gettimeofday({1170749541, 733165}, NULL) = 0 <0.000015>
read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000019>
read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000020>
read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000017>
read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
1024) = 1024 <0.000020>
gettimeofday({1170749541, 733527}, NULL) = 0 <0.000014>
2, sql-bench is the same(only use 'test-create'),
here is the pattern of r4:
read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.110106>
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000008>
write(3, "c\0\0\0\3create table bench_127 (i i"..., 103) = 103 <0.000008>
read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.121058>
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000113>
write(3, "c\0\0\0\3create table bench_128 (i i"..., 103) = 103 <0.000017>
read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.110034>
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
write(3, "c\0\0\0\3create table bench_129 (i i"..., 103) = 103 <0.000017>
and ext3:
read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.003257>
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
write(3, "c\0\0\0\3create table bench_805 (i i"..., 103) = 103 <0.000016>
read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.004001>
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
write(3, "c\0\0\0\3create table bench_806 (i i"..., 103) = 103 <0.000008>
read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.003697>
poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
write(3, "c\0\0\0\3create table bench_807 (i i"..., 103) = 103 <0.000018>
yes...read() on r4 costs ~0.11s while ext3 ~0.003s, definitely the
reason why r4 costs 2667s on create tables and ext3's 203s
3, mongo_read.c in mongo tests uses a read(..., ..., 4096), and the
result is good for r4.
4, 'cp' uses a read(..., ..., 65536), and the result is good for r4 too.
(a part of pattern when copying a big file)
read(3, ":\0064o\270\276\211(\236\241\242\205!\372\375Z\371/\30"...,
65536) = 65536 <0.000067>
write(4, ":\0064o\270\276\211(\236\241\242\205!\372\375Z\371/\30"...,
65536) = 65536 <0.000093>
read(3, "\37X\t\205\334\210\242E%8\t\211\2c\365\37\363\35\305%\206"...,
65536) = 65536 <0.000217>
write(4, "\37X\t\205\334\210\242E%8\t\211\2c\365\37\363\35\305%\206"...,
65536) = 65536 <0.000083>
read(3, "\275\205%\263\0\273M\206\200\24\31\243\204\37!\252\231"...,
65536) = 65536 <0.000066>
write(4, "\275\205%\263\0\273M\206\200\24\31\243\204\37!\252\231"...,
65536) = 65536 <0.000081>
5, The Conclusion "MAYBE": JFS uses "generic_file_*" on read()/write()
and performs best in iozone/sql-bench. r3 uses "generic_file_read" on
read() and performs good on sql-bench too. r4 uses its own
"read_unix_file" on read(), behaves worst on iozone/sql-bench and best
on mongo_read/cp. Anyhow, read_unix_file() must be improved(it is not
be possible replaced by generic_file_read directly).
Comments...?
On Wednesday 24 January 2007 17:05, Xu CanHao wrote:
> Hi!
>
> I've got a benchmark about "reiser4 on mysql" and found a remarkable
> extremely low performance, i managed to turn off fsync() in
> fs/reiser4/plugin/file/file.c (nullify the sync_unix_file() function),
> but it STILL VERY SLOW. I could not found any information about both
> in the mailing-list and google-groups. Here is the detail:
>
> C2.26+I845G+256MB+WD80GB
> Slackware 11.0(Vanilla 2.6.18.3+r4_patch+1.0.5)
> mysql-5.0.24a
> testing use the "sql-bench", all result in seconds.
>
> Alter ATIS Big Connect Create Insert
> Ext3.o 32 21 25 221 203 1979
> JFS 15 21 25 223 114 1711
> XFS 22 22 25 229 1091 1744
> R3 29 20 25 224 194 1731
> R4 70 73 27 276 2667 3499
> nofsync 51 72 26 271 594 3227
>
> Seems even R4 w/o fsync speeds up abit, it's still TERRIBLY SLOW.
> could you tell me why?
>> 6.What else performance bottlenecks do you know, except
> fsync/sql-bench? Could you give me a list?
>
I used to benchmark with iozone and iozone -B. Last time I did reiser4
did not perforrm well on it.
^ permalink raw reply [flat|nested] 2+ messages in thread
* Fwd: Investigate on r4 iozone/sql-bench performance bottleneck: stage one
[not found] ` <6ec7a4340702080306k681b16c8raa58a9408467157d@mail.gmail.com>
@ 2007-02-08 11:13 ` Xu CanHao
0 siblings, 0 replies; 2+ messages in thread
From: Xu CanHao @ 2007-02-08 11:13 UTC (permalink / raw)
To: reiserfs-list
---------- Forwarded message ----------
From: Xu CanHao <xucanhao@gmail.com>
Date: 08.02.2007 19:06
Subject: Re: Investigate on r4 iozone/sql-bench performance
bottleneck: stage one
To: "Vladimir V. Saveliev" <vs@namesys.com>
Yes, But not ext3, it's the champion JFS:
I straced JFS/r3/r4 to some file on the test-create:
I wrote a small shell script to calculate the
read()/write()/fdatasync() that straced(with -ff):
#100 samples of fdatasync()
#cat trace-JFS | grep fdatasync\(27\) | head -n100 | sed
's/.*<\(.*\)>/\1/' | awk 'NR==1{min=$0}{total+=$0;if ($0>max)
max=$0;if ($0<min) min=$0}END{print
"Hi:",max,"Lo:",min,"Sum:",total,"Avg:",total/NR,"Num:",NR}'
#4000 samples of write()
#cat trace-JFS | grep write\(27 | head -n4000 | sed 's/.*<\(.*\)>/\1/'
| awk 'NR==1{min=$0}{total+=$0;if ($0>max) max=$0;if ($0<min)
min=$0}END{print
"Hi:",max,"Lo:",min,"Sum:",total,"Avg:",total/NR,"Num:",NR}'
#600 samples of read()
#cat trace-JFS | grep read\(27.*\<0.* | head -n600 | sed
's/.*<\(.*\)>/\1/' | awk 'NR==1{min=$0}{total+=$0;if ($0>max)
max=$0;if ($0<min) min=$0}END{print
"Hi:",max,"Lo:",min,"Sum:",total,"Avg:",total/NR,"Num:",NR}'
The Result is:
read():
JFS: Hi: 0.000466 Lo: 0.000007 Sum: 0.013141 Avg: 1.99408e-05 Num: 600
r3: Hi: 0.000604 Lo: 0.000007 Sum: 0.01463 Avg: 2.3408e-05 Num: 600
r4: Hi: 0.000823 Lo: 0.000010 Sum: 0.020105 Avg: 3.19127e-05 Num: 600
write():
JFS: Hi: 0.013131 Lo: 0.000006 Sum: 0.101672 Avg: 2.5418e-05 Num: 4000
r3: Hi: 0.001775 Lo: 0.000006 Sum: 0.097671 Avg: 2.44177e-05 Num: 4000
r4: Hi: 0.002837 Lo: 0.000007 Sum: 0.124866 Avg: 3.12165e-05 Num: 4000
fdatasync():
JFS: Hi: 0.008264 Lo: 0.000625 Sum: 0.095227 Avg: 0.00095227 Num: 100
r3: Hi: 0.114442 Lo: 0.002116 Sum: 0.422417 Avg: 0.00422417 Num: 100
r4: Hi: 0.115162 Lo: 0.045747 Sum: 7.12055 Avg: 0.0712055 Num: 100
SO, the conclusion maybe: fdatasync() ruined r4, but wait.....
Alter ATIS Big Connect Create Insert
Ext3.o 32 21 25 221 203 1979
JFS 15 21 25 223 114 1711
XFS 22 22 25 229 1091 1744
R3 29 20 25 224 194 1731
R4 70 73 27 276 2667 3499
R4 51 72 26 271 594 3227(sync_unix_file() emptied)
R4(!!) 7 21 25 219 75
....(sync_unix_file() emptied && use generic_file_read() instead)
YES, YES, YES....... the read_unix_file() also sucks. these two must
be critical performance flaw of r4 and need an immediately
improvement...(I KNOW empty the fsync/fdatasync is a bad idea, but
just for a reference)
PS(!!):
I tried replacing "read_unix_file()" with "generic_file_read()" in
plugin/object.c, it did not crash but some mysteries thing happened:
A->if I do a "make modules"-> "make modules_install" ->stop_mysql
->umount -> rmmod-> modprobe->
mkfs.reiser4&&mount&&mysql_install_db&&start_mysql, mysql returns a
"access denied error", the same process I do with ext3 behaves normal.
B->if I do a "make modules"-> "make modules_install" ->stop_mysql
->umount -> rmmod-> modprobe-> mount&&start_mysql(NO mkfs.reiser4, NO
mysql_install_db, just keep an original(before the code changes made)
r4 partition unchanged), mysql works good.
so, there must be something different of such replacement(is the above clear?).
2007/2/8, Vladimir V. Saveliev <vs@namesys.com>:
> òÕÄÄÝ
>
> On Thursday 08 February 2007 07:18, you wrote:
> > OK, I think I discovered some reason why sql-bench slow. The sql-bench
> > do alot create/select/update/insert/delete operations, which heavily
> > read()/write()/fsync()/fdatasync().
> >
> > BUT r3 is still as slow at fsync() as r4, why r3 much more faster than
> > r4 is still need some days of investment(maybe try
> > nofsync+generic_file_read for r4?).
> >
> > Alter ATIS Big Connect Create Insert
> > Ext3.o 32 21 25 221 203 1979
> > JFS 15 21 25 223 114 1711
> > XFS 22 22 25 229 1091 1744
> > R3 29 20 25 224 194 1731
> > R4 70 73 27 276 2667 3499
>
> Can you please try to separate and strace create phase of the benchmark for ext3 and reiser4?
>
> > nofsync 51 72 26 271 594 3227
> >
> >
> >
> > 2007/2/7, Xu CanHao <xucanhao@gmail.com>:
> > > Hi!
> > >
> > > 1, I tried replacing "read_unix_file()" with "generic_file_read" in
> > > plugin/object.c, it did not crash but some mysteries thing happened:
> > >
> > > A->if I do a "make modules"-> "make modules_install" ->stop_mysql
> > > ->umount -> rmmod-> modprobe->
> > > mkfs.reiser4&&mount&&mysql_install_db&&start_mysql, mysql returns a
> > > "access denied error", the same process I do with ext3 behaves normal.
> > > B->if I do a "make modules"-> "make modules_install" ->stop_mysql
> > > ->umount -> rmmod-> modprobe-> mount&&start_mysql(NO mkfs.reiser4, NO
> > > mysql_install_db, just keep an original(before the code changes made)
> > > r4 partition unchanged), mysql works good.
> > >
> > > so, there must be something different of such replacement.
> > >
> > > 2, If I take "B", r4 uses "generic_file_read" as read(). iozone
> > > read-bench numbers raised from ~800000 to ~1600000, seems pretty good.
> > > BUT when I take test-create on sql-bench, I found avg read() costs
> > > decreased from ~0.11s to ~0.07s, STILL slow compares with ext3.
> > >
> > > 3, What's more mysteries, the read(fd) performed by test-create is
> > > actually a fd by socket(PF_FILE, SOCK_STREAM, 0), and the following
> > > connect() set the path to "/var/run/mysql/mysql.sock"(my /var/run.....
> > > is reiser3). Why would such a circumstance(performance ext3/r4)
> > > happen?
> > >
> > > 2007/2/7, Vladimir V. Saveliev <vs@namesys.com>:
> > > > Hello
> > > >
> > > > On Tuesday 06 February 2007 11:37, Xu CanHao wrote:
> > > > > Hi!
> > > > >
> > > > > I've made an analysis of r4 performance bottleneck on sql-bench/iozone
> > > > > recently, and here is the conclusion:
> > > > >
> > > > > 1, default iozone benchmarks(-Ra) only involves
> > > > > read()/write()/fread()/fwrite()...etc, although many fsync() during
> > > > > iozone, the fsync() time is not calculated in the result, the function
> > > > > invocation pattern is like(iozone -s 4K -r 1K):
> > > > >
> > > > > gettimeofday({1170749541, 313179}, NULL) = 0 <0.000015>
> > > > > write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000174>
> > > > > write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000060>
> > > > > write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000057>
> > > > > write(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000094>
> > > > > gettimeofday({1170749541, 313904}, NULL) = 0 <0.000008>
> > > > >
> > > > >
> > > > > gettimeofday({1170749541, 733165}, NULL) = 0 <0.000015>
> > > > > read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000019>
> > > > > read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000020>
> > > > > read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000017>
> > > > > read(3, "vvvvvvvv\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > > > 1024) = 1024 <0.000020>
> > > > > gettimeofday({1170749541, 733527}, NULL) = 0 <0.000014>
> > > > >
> > > > > 2, sql-bench is the same(only use 'test-create'),
> > > > >
> > > > > here is the pattern of r4:
> > > > >
> > > > > read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.110106>
> > > > > poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000008>
> > > > > write(3, "c\0\0\0\3create table bench_127 (i i"..., 103) = 103 <0.000008>
> > > > > read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.121058>
> > > > > poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000113>
> > > > > write(3, "c\0\0\0\3create table bench_128 (i i"..., 103) = 103 <0.000017>
> > > > > read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.110034>
> > > > > poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
> > > > > write(3, "c\0\0\0\3create table bench_129 (i i"..., 103) = 103 <0.000017>
> > > > >
> > > > > and ext3:
> > > > >
> > > > > read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.003257>
> > > > > poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
> > > > > write(3, "c\0\0\0\3create table bench_805 (i i"..., 103) = 103 <0.000016>
> > > > > read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.004001>
> > > > > poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
> > > > > write(3, "c\0\0\0\3create table bench_806 (i i"..., 103) = 103 <0.000008>
> > > > > read(3, "\7\0\0\1\0\0\0\2\0\0\0", 16384) = 11 <0.003697>
> > > > > poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 <0.000017>
> > > > > write(3, "c\0\0\0\3create table bench_807 (i i"..., 103) = 103 <0.000018>
> > > > >
> > > > > yes...read() on r4 costs ~0.11s while ext3 ~0.003s, definitely the
> > > > > reason why r4 costs 2667s on create tables and ext3's 203s
> > > > >
> > > >
> > > > read is called to read 16384 bytes, and only 11 bytes get read. Maybe reiser4 tries to read non existent data too hard.
> > > >
> > > > > 3, mongo_read.c in mongo tests uses a read(..., ..., 4096), and the
> > > > > result is good for r4.
> > > > >
> > > > > 4, 'cp' uses a read(..., ..., 65536), and the result is good for r4 too.
> > > > > (a part of pattern when copying a big file)
> > > > > read(3, ":\0064o\270\276\211(\236\241\242\205!\372\375Z\371/\30"...,
> > > > > 65536) = 65536 <0.000067>
> > > > > write(4, ":\0064o\270\276\211(\236\241\242\205!\372\375Z\371/\30"...,
> > > > > 65536) = 65536 <0.000093>
> > > > > read(3, "\37X\t\205\334\210\242E%8\t\211\2c\365\37\363\35\305%\206"...,
> > > > > 65536) = 65536 <0.000217>
> > > > > write(4, "\37X\t\205\334\210\242E%8\t\211\2c\365\37\363\35\305%\206"...,
> > > > > 65536) = 65536 <0.000083>
> > > > > read(3, "\275\205%\263\0\273M\206\200\24\31\243\204\37!\252\231"...,
> > > > > 65536) = 65536 <0.000066>
> > > > > write(4, "\275\205%\263\0\273M\206\200\24\31\243\204\37!\252\231"...,
> > > > > 65536) = 65536 <0.000081>
> > > > >
> > > > > 5, The Conclusion "MAYBE": JFS uses "generic_file_*" on read()/write()
> > > > > and performs best in iozone/sql-bench. r3 uses "generic_file_read" on
> > > > > read() and performs good on sql-bench too. r4 uses its own
> > > > > "read_unix_file" on read(), behaves worst on iozone/sql-bench and best
> > > > > on mongo_read/cp. Anyhow, read_unix_file() must be improved(it is not
> > > > > be possible replaced by generic_file_read directly).
> > > > >
> > > > > Comments...?
> > > >
> > > > We tried to implement reiser4 read via generic_file_read and that did not make substantial difference.
> > > > I do not think that we tested it with sql-bench, though.
> > > >
> > > > >
> > > > >
> > > > > On Wednesday 24 January 2007 17:05, Xu CanHao wrote:
> > > > > > Hi!
> > > > > >
> > > > > > I've got a benchmark about "reiser4 on mysql" and found a remarkable
> > > > > > extremely low performance, i managed to turn off fsync() in
> > > > > > fs/reiser4/plugin/file/file.c (nullify the sync_unix_file() function),
> > > > > > but it STILL VERY SLOW. I could not found any information about both
> > > > > > in the mailing-list and google-groups. Here is the detail:
> > > > > >
> > > > > > C2.26+I845G+256MB+WD80GB
> > > > > > Slackware 11.0(Vanilla 2.6.18.3+r4_patch+1.0.5)
> > > > > > mysql-5.0.24a
> > > > > > testing use the "sql-bench", all result in seconds.
> > > > > >
> > > > > > Alter ATIS Big Connect Create Insert
> > > > > > Ext3.o 32 21 25 221 203 1979
> > > > > > JFS 15 21 25 223 114 1711
> > > > > > XFS 22 22 25 229 1091 1744
> > > > > > R3 29 20 25 224 194 1731
> > > > > > R4 70 73 27 276 2667 3499
> > > > > > nofsync 51 72 26 271 594 3227
> > > > > >
> > > > > > Seems even R4 w/o fsync speeds up abit, it's still TERRIBLY SLOW.
> > > > > > could you tell me why?
> > > > >
> > > > >
> > > > >
> > > > > >> 6.What else performance bottlenecks do you know, except
> > > > > > fsync/sql-bench? Could you give me a list?
> > > > > >
> > > > >
> > > > > I used to benchmark with iozone and iozone -B. Last time I did reiser4
> > > > > did not perforrm well on it.
> > > > >
> > > > >
> > > >
> > >
> >
> >
>
^ permalink raw reply [flat|nested] 2+ messages in thread
end of thread, other threads:[~2007-02-08 11:13 UTC | newest]
Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2007-02-06 8:37 Investigate on r4 iozone/sql-bench performance bottleneck: stage one Xu CanHao
[not found] ` <6ec7a4340702062302t24d0fa3bv9c17e9b89e1d9f00@mail.gmail.com>
[not found] ` <6ec7a4340702072018k6cc75c3cgc99551db01ff6ce4@mail.gmail.com>
[not found] ` <200702081354.03644.vs@namesys.com>
[not found] ` <6ec7a4340702080306k681b16c8raa58a9408467157d@mail.gmail.com>
2007-02-08 11:13 ` Fwd: " Xu CanHao
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.