[rhelv6-beta-list] A simple program runs under KVM faster than under nake PC.

Kirby Zhou kirbyzhou at sohu-rd.com
Mon Aug 9 06:39:12 UTC 2010


But there is no I/O request.
It is just a simple PURE CPU program.
It calls openssl-aes and zlib-crc32 only.

[root at xen-727057^10.227 ~]# time ssh 10.12.10.192 strace -ftT ./a.out 1
10000
06:38:15 execve("./a.out", ["./a.out", "1", "10000"], [/* 17 vars */]) = 0
<0.000887>
06:38:15 brk(0)                         = 0x1b374000 <0.000038>
06:38:15 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x2b2a6323d000 <0.000032>
06:38:15 uname({sys="Linux", node="djt_10_192", ...}) = 0 <0.000022>
06:38:15 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or
directory) <0.000047>
06:38:15 open("/etc/ld.so.cache", O_RDONLY) = 3 <0.000036>
06:38:15 fstat(3, {st_mode=S_IFREG|0644, st_size=70638, ...}) = 0 <0.000024>
06:38:15 mmap(NULL, 70638, PROT_READ, MAP_PRIVATE, 3, 0) = 0x2b2a6323e000
<0.000018>
06:38:15 close(3)                       = 0 <0.000023>
06:38:15 open("/lib64/libcrypto.so.6", O_RDONLY) = 3 <0.000033>
06:38:15 read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200\232\5\364;\0\0\0"...,
832) = 832 <0.000018>
06:38:15 fstat(3, {st_mode=S_IFREG|0755, st_size=1366272, ...}) = 0
<0.000015>
06:38:15 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x2b2a63250000 <0.000018>
06:38:15 mmap(0x3bf4000000, 3475344, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bf4000000 <0.000035>
06:38:15 mprotect(0x3bf412d000, 2093056, PROT_NONE) = 0 <0.000024>
06:38:15 mmap(0x3bf432c000, 135168, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x12c000) = 0x3bf432c000 <0.000031>
06:38:15 mmap(0x3bf434d000, 14224, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3bf434d000 <0.000020>
06:38:15 close(3)                       = 0 <0.000020>
06:38:15 open("/usr/lib64/libz.so.1", O_RDONLY) = 3 <0.000036>
06:38:15 read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320\37@\357;\0\0\0"..., 832)
= 832 <0.000017>
06:38:15 fstat(3, {st_mode=S_IFREG|0755, st_size=85928, ...}) = 0 <0.000015>
06:38:15 mmap(0x3bef400000, 2178920, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bef400000 <0.000018>
06:38:15 mprotect(0x3bef414000, 2093056, PROT_NONE) = 0 <0.000024>
06:38:15 mmap(0x3bef613000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13000) = 0x3bef613000 <0.000020>
06:38:15 close(3)                       = 0 <0.000014>
06:38:15 open("/usr/lib64/libstdc++.so.6", O_RDONLY) = 3 <0.000037>
06:38:15 read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\364\4\363;\0\0\0"...,
832) = 832 <0.000022>
06:38:15 fstat(3, {st_mode=S_IFREG|0755, st_size=976312, ...}) = 0
<0.000014>
06:38:15 mmap(0x3bf3000000, 3145600, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bf3000000 <0.000026>
06:38:15 mprotect(0x3bf30e6000, 2093056, PROT_NONE) = 0 <0.000023>
06:38:15 mmap(0x3bf32e5000, 36864, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xe5000) = 0x3bf32e5000 <0.000021>
06:38:15 mmap(0x3bf32ee000, 73600, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3bf32ee000 <0.000020>
06:38:15 close(3)                       = 0 <0.000021>
06:38:15 open("/lib64/libm.so.6", O_RDONLY) = 3 <0.000042>
06:38:15 read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`>\300\356;\0\0\0"..., 832) =
832 <0.000021>
06:38:15 fstat(3, {st_mode=S_IFREG|0755, st_size=615136, ...}) = 0
<0.000015>
06:38:15 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x2b2a63251000 <0.000017>
06:38:15 mmap(0x3beec00000, 2629848, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3beec00000 <0.000026>
06:38:15 mprotect(0x3beec82000, 2093056, PROT_NONE) = 0 <0.000023>
06:38:15 mmap(0x3beee81000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x81000) = 0x3beee81000 <0.000020>
06:38:15 close(3)                       = 0 <0.000022>
06:38:15 open("/lib64/libgcc_s.so.1", O_RDONLY) = 3 <0.000030>
06:38:15 read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\36@\360;\0\0\0"..., 832) =
832 <0.000021>
06:38:15 fstat(3, {st_mode=S_IFREG|0755, st_size=58400, ...}) = 0 <0.000015>
06:38:15 mmap(0x3bf0400000, 2151784, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bf0400000 <0.000018>
06:38:15 mprotect(0x3bf040d000, 2097152, PROT_NONE) = 0 <0.000022>
06:38:15 mmap(0x3bf060d000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xd000) = 0x3bf060d000 <0.000020>
06:38:15 close(3)                       = 0 <0.000015>
06:38:15 open("/lib64/libc.so.6", O_RDONLY) = 3 <0.000033>
06:38:15 read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\332A\356;\0\0\0"...,
832) = 832 <0.000016>
06:38:15 fstat(3, {st_mode=S_IFREG|0755, st_size=1717800, ...}) = 0
<0.000015>
06:38:15 mmap(0x3bee400000, 3498328, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bee400000 <0.000018>
06:38:15 mprotect(0x3bee54e000, 2093056, PROT_NONE) = 0 <0.000024>
06:38:15 mmap(0x3bee74d000, 20480, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14d000) = 0x3bee74d000 <0.000021>
06:38:15 mmap(0x3bee752000, 16728, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3bee752000 <0.000021>
06:38:15 close(3)                       = 0 <0.000044>
06:38:15 open("/lib64/libdl.so.2", O_RDONLY) = 3 <0.000028>
06:38:15 read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\16\200\356;\0\0\0"...,
832) = 832 <0.000017>
06:38:15 fstat(3, {st_mode=S_IFREG|0755, st_size=23360, ...}) = 0 <0.000015>
06:38:15 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x2b2a63252000 <0.000016>
06:38:15 mmap(0x3bee800000, 2109696, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bee800000 <0.000027>
06:38:15 mprotect(0x3bee802000, 2097152, PROT_NONE) = 0 <0.000022>
06:38:15 mmap(0x3beea02000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x3beea02000 <0.000020>
06:38:15 close(3)                       = 0 <0.000022>
06:38:15 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x2b2a63253000 <0.000030>
06:38:15 arch_prctl(ARCH_SET_FS, 0x2b2a63253660) = 0 <0.000055>
06:38:15 mprotect(0x3beea02000, 4096, PROT_READ) = 0 <0.000050>
06:38:15 mprotect(0x3bee74d000, 16384, PROT_READ) = 0 <0.000096>
06:38:15 mprotect(0x3beee81000, 4096, PROT_READ) = 0 <0.000042>
06:38:15 mprotect(0x3bf32e5000, 24576, PROT_READ) = 0 <0.000057>
06:38:15 mprotect(0x3bee21b000, 4096, PROT_READ) = 0 <0.000073>
06:38:15 munmap(0x2b2a6323e000, 70638)  = 0 <0.000046>
06:38:15 brk(0)                         = 0x1b374000 <0.000084>
06:38:15 brk(0x1b395000)                = 0x1b395000 <0.000017>
=====>>>>> there I do call AES and CRC32
06:38:18 fstat(1, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 <0.000035>
06:38:18 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x2b2a6323e000 <0.000035>
crc:a4580383
06:38:18 write(1, "crc:a4580383\n", 13) = 13 <0.000049>
06:38:18 exit_group(0)                  = ?

real    0m3.115s
user    0m0.000s
sys     0m0.000s


Regards,
   Kirby Zhou    
   from   SOHU-RD   +86-10-6272-8261


-----Original Message-----
From: rhelv6-beta-list-bounces at redhat.com
[mailto:rhelv6-beta-list-bounces at redhat.com] On Behalf Of Roel Gloudemans
Sent: Monday, August 09, 2010 1:34 PM
To: Red Hat Enterprise Linux 6 (Santiago) Beta releases discussion
mailing-list
Subject: Re: [rhelv6-beta-list] A simple program runs under KVM faster than
under nake PC.

Could this be an effect of "double caching"? The VM has its own cache, but
since KVM VM's are just normal processes on the host, the host caches the
I/O as well. I think you need to add:

<driver name="qemu" cache="none"/>

To your VM definition file to turn it off.

Cheers,
Roel.

----- Original Message -----
> From: "Kirby Zhou" <kirbyzhou at sohu-rd.com>
> To: "Red Hat Enterprise Linux 6 (Santiago) Beta releases discussion
mailing-list" <rhelv6-beta-list at redhat.com>
> Sent: Monday, 9 August, 2010 4:43:24 AM
> Subject: Re: [rhelv6-beta-list] A simple program runs under KVM faster
than under nake PC.
> A simple fact is that RHEL5 DO NOT have KSM.
> 
> RHEL6/nake
> [root at djt_10_47 ~]# echo 2 > /sys/kernel/mm/ksm/run
> [root at xen-727057^10.227 ~]# time ssh 10.12.10.47 ./a.out 1 10000
> crc:a4580383
> 
> real 0m5.628s
> user 0m0.000s
> sys 0m0.000s
> 
> RHEL6/KVM
> [root at djt_10_199 ~]# echo 2 > /sys/kernel/mm/ksm/run
> [root at xen-727057^10.227 ~]# time ssh 10.12.10.199 ./a.out 1 10000
> crc:a4580383
> 
> real 0m3.139s
> user 0m0.000s
> sys 0m0.000s
> 
> Regards
> Kirby Zhou
> 
> -----Original Message-----
> From: rhelv6-beta-list-bounces at redhat.com
> [mailto:rhelv6-beta-list-bounces at redhat.com] On Behalf Of Sean Pajot
> Sent: Monday, August 09, 2010 1:34 AM
> To: Red Hat Enterprise Linux 6 (Santiago) Beta releases discussion
> mailing-list
> Subject: Re: [rhelv6-beta-list] A simple program runs under KVM faster
> than
> under nake PC.
> 
> Crazy idea. How "simple" is this program? If you're using KVM, then
> KSM will
> 
> be merging identical pages. This can benefit CPU cache lines. Would
> this
> account for the performance improvement?
> 
> Try turning off KSM, power down/up your test VM to flush all the
> pages, and
> test again. It should also be possible to modify your app to use KSM
> for
> itself on bare metal.
> 
> Kirby Zhou wrote:
> >
> >
> > Both RHEL5/RHEL6 encounter the same situation.
> >
> > Is there any potential bug?
> >
> >
> >
> > ]# g++ testaes.cpp -lcrypto -lz
> >
> >
> >
> > RHEL6 nake
> >
> > [root at djt_10_47 ~]# time ./a.out 1 10000 | head -n 10000 | md5sum
> >
> > caba4fd0bae809e634b5cd8acd3424f2 -
> >
> >
> >
> > real 0m5.778s
> >
> > user 0m5.774s
> >
> > sys 0m0.014s
> >
> >
> >
> > RHEL6 KVM
> >
> > [root at djt_10_199 ~]# time ./a.out 1 10000 | head -n 10000 | md5sum
> >
> > 51722dcdf339f131a89eb2dc106d8dbe -
> >
> >
> >
> > real 0m3.272s
> >
> > user 0m3.266s
> >
> > sys 0m0.032s
> >
> >
> >
> > RHEL5 nake
> >
> > [@djt_10_48 ~]# time ./a.out 1 10000 | head -n 10000 | md5sum
> >
> > 51722dcdf339f131a89eb2dc106d8dbe -
> >
> >
> >
> > real 0m5.786s
> >
> > user 0m5.780s
> >
> > sys 0m0.008s
> >
> >
> >
> > RHEL5 KVM
> >
> > [@djt_10_192 ~]# time ./a.out 1 10000 | head -n 10000 | md5sum
> >
> > 51722dcdf339f131a89eb2dc106d8dbe -
> >
> >
> >
> > real 0m3.243s
> >
> > user 0m2.864s
> >
> > sys 0m0.387s
> >
> >
> >
> >
> >
> >
> >
> >   Regards
> >
> >   Kirby Zhou
> >
> >
> 
> _______________________________________________
> rhelv6-beta-list mailing list
> rhelv6-beta-list at redhat.com
> https://www.redhat.com/mailman/listinfo/rhelv6-beta-list
> 
> _______________________________________________
> rhelv6-beta-list mailing list
> rhelv6-beta-list at redhat.com
> https://www.redhat.com/mailman/listinfo/rhelv6-beta-list

_______________________________________________
rhelv6-beta-list mailing list
rhelv6-beta-list at redhat.com
https://www.redhat.com/mailman/listinfo/rhelv6-beta-list




More information about the rhelv6-beta-list mailing list