Is it reasonable to compare outputs between JMH and hprof?
Bernd Eckenfels
ecki at zusammenkunft.net
Thu Dec 4 05:38:20 UTC 2014
Hello,
I would use the power of JMH to test this with different array sizes and with and without provider instantiation. I did that a while back for MDC/MAC, and SHA256 is not that attractive anymore as SHA512 is faster (and with SHA512-256 not bigger)
(Java7Windows7:)
https://gist.github.com/ecki/a4d598c4231a0165d0a1
Benchmark (bufsize) Mode Samples Score Score error Units
n.e.t.j.HashBenchmark.testHmacSHA1 1 avgt 3 0,005 0,001 ms/op
n.e.t.j.HashBenchmark.testHmacSHA1 1024 avgt 3 0,015 0,005 ms/op
n.e.t.j.HashBenchmark.testHmacSHA1 1048576 avgt 3 9,479 1,836 ms/op
n.e.t.j.HashBenchmark.testHmacSHA256 1 avgt 3 0,006 0,003 ms/op
n.e.t.j.HashBenchmark.testHmacSHA256 1024 avgt 3 0,021 0,010 ms/op
n.e.t.j.HashBenchmark.testHmacSHA256 1048576 avgt 3 14,211 2,847 ms/op
n.e.t.j.HashBenchmark.testHmacSHA512 1 avgt 3 0,009 0,002 ms/op
n.e.t.j.HashBenchmark.testHmacSHA512 1024 avgt 3 0,021 0,011 ms/op
n.e.t.j.HashBenchmark.testHmacSHA512 1048576 avgt 3 11,727 11,595 ms/op
n.e.t.j.HashBenchmark.testMD5 1 avgt 3 0,001 0,001 ms/op
n.e.t.j.HashBenchmark.testMD5 1024 avgt 3 0,007 0,001 ms/op
n.e.t.j.HashBenchmark.testMD5 1048576 avgt 3 6,102 0,360 ms/op
n.e.t.j.HashBenchmark.testMD5Reuse 1 avgt 3 0,000 0,000 ms/op
n.e.t.j.HashBenchmark.testMD5Reuse 1024 avgt 3 0,007 0,004 ms/op
n.e.t.j.HashBenchmark.testMD5Reuse 1048576 avgt 3 6,210 2,319 ms/op
n.e.t.j.HashBenchmark.testSHA1 1 avgt 3 0,001 0,003 ms/op
n.e.t.j.HashBenchmark.testSHA1 1024 avgt 3 0,011 0,018 ms/op
n.e.t.j.HashBenchmark.testSHA1 1048576 avgt 3 9,446 0,750 ms/op
n.e.t.j.HashBenchmark.testSHA1Reuse 1 avgt 3 0,001 0,000 ms/op
n.e.t.j.HashBenchmark.testSHA1Reuse 1024 avgt 3 0,010 0,002 ms/op
n.e.t.j.HashBenchmark.testSHA1Reuse 1048576 avgt 3 9,455 3,341 ms/op
n.e.t.j.HashBenchmark.testSHA256 1 avgt 3 0,002 0,000 ms/op
n.e.t.j.HashBenchmark.testSHA256 1024 avgt 3 0,016 0,008 ms/op
n.e.t.j.HashBenchmark.testSHA256 1048576 avgt 3 13,938 2,390 ms/op
n.e.t.j.HashBenchmark.testSHA256Reuse 1 avgt 3 0,001 0,001 ms/op
n.e.t.j.HashBenchmark.testSHA256Reuse 1024 avgt 3 0,017 0,007 ms/op
n.e.t.j.HashBenchmark.testSHA256Reuse 1048576 avgt 3 15,431 14,422 ms/op
n.e.t.j.HashBenchmark.testSHA512 1 avgt 3 0,003 0,001 ms/op
n.e.t.j.HashBenchmark.testSHA512 1024 avgt 3 0,015 0,010 ms/op
n.e.t.j.HashBenchmark.testSHA512 1048576 avgt 3 11,532 1,528 ms/op
n.e.t.j.HashBenchmark.testSHA512Reuse 1 avgt 3 0,002 0,000 ms/op
n.e.t.j.HashBenchmark.testSHA512Reuse 1024 avgt 3 0,013 0,009 ms/op
n.e.t.j.HashBenchmark.testSHA512Reuse 1048576 avgt 3 10,801 2,124 ms/op
But to your question. They way the Profiler samples the stack and the fact that SHA1 and SHA2 are implementations with different depths, they are hard to compare. You would actually have to compare the time spent in high level methods (main/sig/update) not the low level code. And you need to run the test longer otherwise you see only startup/shutdown samples.
Besides that Profilers greatly influence the runtime and behavior, its not at all useable for micro benchmarkings (at least not unless you have less intrusive profilers like cpu counter assisted kernel stuff (Linux perf)). Somewhat related a recent article: http://psy-lob-saw.blogspot.de/2014/12/the-escape-of-arraylistiterator.html
I see this:
public static void main(String args[]) throws Exception {
int i=0;
MessageDigest md256 = MessageDigest.getInstance("SHA-256");
MessageDigest md1 = MessageDigest.getInstance("SHA-1");
for(int t=0;t<100;t++) {
i = Arrays.hashCode(sig1(md1));
i += Arrays.hashCode(sig256(md256));}
System.out.println(i);
}
static byte[] sig1(MessageDigest md) throws Exception {
md.update(new byte[10000]);
return md.digest();
}
static byte[] sig256(MessageDigest md) throws Exception {
md.update(new byte[10000]);
return md.digest();
}
rank self accum count trace method
23 0.05% 99.25% 100 303130 sun.security.provider.DigestBase.engineUpdate
...
27 0.05% 99.45% 100 303096 sun.security.provider.DigestBase.engineUpdate
TRACE 303130:
sun.security.provider.DigestBase.engineUpdate(DigestBase.java:Unknown line)
java.security.MessageDigest$Delegate.engineUpdate(MessageDigest.java:Unknown line)
java.security.MessageDigest.update(MessageDigest.java:Unknown line)
net.eckenfels.test.jmh.HashMain.sig256(HashMain.java:Unknown line)
net.eckenfels.test.jmh.HashMain.main(HashMain.java:Unknown line)
TRACE 303096:
sun.security.provider.DigestBase.engineUpdate(DigestBase.java:Unknown line)
java.security.MessageDigest$Delegate.engineUpdate(MessageDigest.java:Unknown line)
java.security.MessageDigest.update(MessageDigest.java:Unknown line)
net.eckenfels.test.jmh.HashMain.sig1(HashMain.java:Unknown line)
net.eckenfels.test.jmh.HashMain.main(HashMain.java:Unknown line)
The test runs 1s without and 40s with profiler. That does tell all IMHO.
Gruss
Bernd
Am Thu, 4 Dec 2014 12:09:49 +0800
schrieb Wang Weijun <weijun.wang at oracle.com>:
> Hi All
>
> I am comparing the difference of SHA-1 and SHA-256. First I wrote a
> JMH benchmark:
>
> @Benchmark
> public void sig1(Blackhole bh) throws Exception {
> bh.consume(sig("SHA-1"));
> }
>
> @Benchmark
> public void sig2(Blackhole bh) throws Exception {
> bh.consume(sig("SHA-256"));
> }
>
> byte[] sig(String alg) throws Exception {
> MessageDigest md = MessageDigest.getInstance(alg);
> md.update(new byte[10000]);
> return md.digest();
> }
>
> The output is
>
> Benchmark Mode Samples Score Error Units
> o.o.b.Weird.sig1 thrpt 5 20984.435 ± 3356.455 ops/s
> o.o.b.Weird.sig2 thrpt 5 13130.330 ± 976.824 ops/s
>
> so the difference is there but not huge.
>
> Then I wrote a simple app with
>
> public static void main(String args[]) throws Exception {
> int i = Arrays.hashCode(sig("SHA-1"));
> i += Arrays.hashCode(sig("SHA-256"));
> System.out.println(i);
> }
>
> static byte[] sig(String alg) throws Exception {
> MessageDigest md = MessageDigest.getInstance(alg);
> md.update(new byte[10000]);
> return md.digest();
> }
>
> and then profile it with -agentlib:hprof=cpu=times, and get
>
> SHA2 1 10.16% 10.16% 156 303276
> sun.security.provider.SHA2.implCompress SHA2 2 6.91% 17.07%
> 9984 303274 sun.security.provider.SHA2.lf_sigma0 SHA2 3 5.28%
> 22.36% 9984 303271 sun.security.provider.SHA2.lf_sigma1 SHA2 4
> 4.61% 26.96% 7488 303269 sun.security.provider.SHA2.lf_delta0
> SHA2 5 4.20% 31.17% 29952 303273
> sun.security.provider.SHA2.lf_S SHA2 7 3.79% 39.16% 7488
> 303266 sun.security.provider.SHA2.lf_delta1 SHA2 9 2.85% 44.99%
> 29952 303270 sun.security.provider.SHA2.lf_S SHA2 13 1.90%
> 54.47% 14976 303267 sun.security.provider.SHA2.lf_S SHA2 17
> 1.49% 61.25% 14976 303264 sun.security.provider.SHA2.lf_S SHA2
> 22 0.81% 66.12% 7488 303265 sun.security.provider.SHA2.lf_R
> SHA2 23 0.81% 66.94% 9984 303275
> sun.security.provider.SHA2.lf_maj SHA2 25 0.81% 68.56% 156
> 303263 sun.security.provider.ByteArrayAccess.b2iBig64 SHA2 27
> 0.68% 70.05% 9984 303272 sun.security.provider.SHA2.lf_ch SHA2
> 31 0.54% 72.63% 7488 303268 sun.security.provider.SHA2.lf_R
> SHA1 34 0.54% 74.25% 156 303224
> sun.security.provider.SHA.implCompress SHA1 43 0.41% 78.05%
> 156 303223 sun.security.provider.ByteArrayAccess.b2iBig64 SHA2 60
> 0.27% 82.66% 2496 303262 java.lang.Integer.reverseBytes SHA2 61
> 0.27% 82.93% 64 303290 sun.security.provider.SHA2.lf_sigma1
> SHA1 116 0.14% 91.06% 2496 303222 java.lang.Integer.reverseBytes
>
> These are calls with SHA (i.e. SHA1) or SHA2 in the stack (depth=4),
> and time for SHA2 vs SHA1 is 45.38% vs 1.09%. With such a small app I
> don't think SHA or SHA2 is called anywhere else. This is jdk9 b40.
>
> Why is the output so different from JMH? Is it reasonable comparing
> them?
>
> Thanks
> Max
>
More information about the security-dev
mailing list