JLBH示例1 –为什么应在上下文中对代码进行基准测试
在這篇文章中:
- 使用JMH和JLBH進行日期序列化的并排示例
- 在微基準中測量日期序列化
- 測量日期序列化作為適當應用程序的一部分
- 如何為您的JLBH基準添加探針
- 了解在上下文中衡量代碼的重要性
在上一篇文章“ JLBH簡介 ”中,我們介紹了JLBH( Chronicle用于測試Chronicle-FIX的延遲測試工具),現在可以作為開源使用。
在接下來的幾篇文章中,我們將看一些示例應用程序:
為例子甘蔗的所有代碼被發現這里在我的GitHub項目:
我在JLBH簡介中提出的觀點之一是,在上下文中對代碼進行基準測試很重要。 這意味著在盡可能接近實際運行環境的環境中對代碼進行基準測試。 這篇文章在實踐中演示了這一點。
讓我們看一下一個相對昂貴的Java操作–日期序列化–并查看需要花費多長時間:
首先,這是JMH基準:
package org.latency.serialisation.date;import net.openhft.affinity.Affinity; import net.openhft.chronicle.core.Jvm; import net.openhft.chronicle.core.OS; import org.openjdk.jmh.annotations.*; import org.openjdk.jmh.runner.Runner; import org.openjdk.jmh.runner.RunnerException; import org.openjdk.jmh.runner.options.Options; import org.openjdk.jmh.runner.options.OptionsBuilder; import org.openjdk.jmh.runner.options.TimeValue;import java.io.*; import java.lang.reflect.InvocationTargetException; import java.util.Date; import java.util.concurrent.TimeUnit;/*** Created to show the effects of running code within more complex code.* Date serialisation as a micro benchmark vs date serialisation inside a TCP call.*/ @State(Scope.Thread) public class DateSerialiseJMH {private final Date date = new Date();public static void main(String[] args) throws InvocationTargetException,IllegalAccessException, RunnerException, IOException, ClassNotFoundException {if (OS.isLinux())Affinity.setAffinity(2);if(Jvm.isDebug()){DateSerialiseJMH jmhParse = new DateSerialiseJMH();jmhParse.test();}else {Options opt = new OptionsBuilder().include(DateSerialiseJMH.class.getSimpleName()).warmupIterations(6).forks(1).measurementIterations(5).mode(Mode.SampleTime).measurementTime(TimeValue.seconds(3)).timeUnit(TimeUnit.MICROSECONDS).build();new Runner(opt).run();}}@Benchmarkpublic Date test() throws IOException, ClassNotFoundException {ByteArrayOutputStream out = new ByteArrayOutputStream();ObjectOutputStream oos = new ObjectOutputStream(out);oos.writeObject(date);ObjectInputStream ois = new ObjectInputStream(new ByteArrayInputStream(out.toByteArray()));return (Date)ois.readObject();} }在我的筆記本電腦(MBP i7)上運行,這些是我得到的結果:
Result "test":4.578 ±(99.9%) 0.046 us/op [Average](min, avg, max) = (3.664, 4.578, 975.872), stdev = 6.320CI (99.9%): [4.533, 4.624] (assumes normal distribution)Samples, N = 206803mean = 4.578 ±(99.9%) 0.046 us/opmin = 3.664 us/opp( 0.0000) = 3.664 us/opp(50.0000) = 4.096 us/opp(90.0000) = 5.608 us/opp(95.0000) = 5.776 us/opp(99.0000) = 8.432 us/opp(99.9000) = 24.742 us/opp(99.9900) = 113.362 us/opp(99.9990) = 847.245 us/opp(99.9999) = 975.872 us/opmax = 975.872 us/op# Run complete. Total time: 00:00:21Benchmark Mode Cnt Score Error UnitsDateSerialiseJMH.test sample 206803 4.578 ± 0.046 us/op 該操作的平均時間為4.5us:
使用JLBH進行測試時,我們得到的結果幾乎相同:
結果如下:
Warm up complete (400000 iterations took 2.934s) -------------------------------- BENCHMARK RESULTS (RUN 1) --------- Run time: 10.0s Correcting for co-ordinated:true Target throughput:100000/s = 1 message every 10us End to End: (1,000,000) 50/90 99/99.9 99.99/99.999 - worst was 4.2 / 5.8 352 / 672 803 / 901 - 934 OS Jitter (13,939) 50/90 99/99.9 99.99 - worst was 8.4 / 17 639 / 4,130 12,850 - 20,450 -------------------------------------------------------------------- -------------------------------- BENCHMARK RESULTS (RUN 2) --------- Run time: 10.0s Correcting for co-ordinated:true Target throughput:100000/s = 1 message every 10us End to End: (1,000,000) 50/90 99/99.9 99.99/99.999 - worst was 4.2 / 5.8 434 / 705 836 / 934 - 967 OS Jitter (11,016) 50/90 99/99.9 99.99 - worst was 8.4 / 17 606 / 770 868 - 1,340 -------------------------------------------------------------------- -------------------------------- BENCHMARK RESULTS (RUN 3) --------- Run time: 10.0s Correcting for co-ordinated:true Target throughput:100000/s = 1 message every 10us End to End: (1,000,000) 50/90 99/99.9 99.99/99.999 - worst was 4.2 / 5.8 434 / 737 901 / 999 - 1,030 OS Jitter (12,319) 50/90 99/99.9 99.99 - worst was 8.4 / 15 573 / 737 803 - 901 ---------------------------------------------------------------------------------------------------- SUMMARY (end to end)---------------Percentile run1 run2 run3 % Variation 50: 4.22 4.22 4.22 0.00 90: 5.76 5.76 5.76 0.00 99: 352.26 434.18 434.18 0.00 99.9: 671.74 704.51 737.28 3.01 99.99: 802.82 835.58 901.12 4.97 worst: 901.12 933.89 999.42 4.47 --------------------------------------------------------------------該操作的平均時間為4.2us:
注意:在這種情況下,使用JLBH相對于JMH沒有優勢。 我只是將代碼作為比較。
現在我們將運行完全相同的操作,但是在TCP調用中,代碼將像這樣工作:
如前一篇文章所述,JLBH允許我們為代碼的任何部分生成延遲配置文件。 我們將為階段3添加一個探針。
package org.latency.serialisation.date;import net.openhft.affinity.Affinity; import net.openhft.chronicle.core.Jvm; import net.openhft.chronicle.core.jlbh.JLBHOptions; import net.openhft.chronicle.core.jlbh.JLBHTask; import net.openhft.chronicle.core.jlbh.JLBH; import net.openhft.chronicle.core.util.NanoSampler;import java.io.*; import java.net.InetSocketAddress; import java.nio.ByteBuffer; import java.nio.ByteOrder; import java.nio.channels.ServerSocketChannel; import java.nio.channels.SocketChannel; import java.util.Date;/*** Created to show the effects of running code within more complex code.* Date serialisation as a micro benchmark vs date serialisation inside a TCP call.*/ public class DateSerialiseJLBHTcpTask implements JLBHTask {private final static int port = 8007;private static final boolean BLOCKING = false;private final int SERVER_CPU = Integer.getInteger("server.cpu", 0);private Date date = new Date();private JLBH lth;private ByteBuffer bb;private SocketChannel socket;private byte[] fixMessageBytes;private NanoSampler dateProbe;public static void main(String[] args) {JLBHOptions lth = new JLBHOptions().warmUpIterations(50_000).iterations(100_000).throughput(20_000).runs(3).recordOSJitter(true).accountForCoordinatedOmmission(true).jlbhTask(new DateSerialiseJLBHTcpTask());new JLBH(lth).start();}@Overridepublic void init(JLBH lth) {this.lth = lth;dateProbe = lth.addProbe("date serialisation ");try {runServer(port);Jvm.pause(200);socket = SocketChannel.open(new InetSocketAddress(port));socket.socket().setTcpNoDelay(true);socket.configureBlocking(BLOCKING);} catch (IOException e) {e.printStackTrace();}String fixMessage = "8=FIX.4.2\u00019=211\u000135=D\u000134=3\u000149=MY-INITIATOR-SERVICE\u000152=20160229-" +"09:04:14.459\u000156=MY-ACCEPTOR-SERVICE\u00011=ABCTEST1\u000111=863913604164909\u000121=3\u000122=5" +"\u000138=1\u000140=2\u000144=200\u000148=LCOM1\u000154=1\u000155=LCOM1\u000159=0\u000160=20160229-09:" +"04:14.459\u0001167=FUT\u0001200=201106\u000110=144\u0001\n";fixMessageBytes = fixMessage.getBytes();int length = fixMessageBytes.length;bb = ByteBuffer.allocateDirect(length).order(ByteOrder.nativeOrder());bb.put(fixMessageBytes);}private void runServer(int port) throws IOException {new Thread(() -> {if (SERVER_CPU > 0) {System.out.println("server cpu: " + SERVER_CPU);Affinity.setAffinity(SERVER_CPU);}ServerSocketChannel ssc = null;SocketChannel socket = null;try {ssc = ServerSocketChannel.open();ssc.bind(new InetSocketAddress(port));System.out.println("listening on " + ssc);socket = ssc.accept();socket.socket().setTcpNoDelay(true);socket.configureBlocking(BLOCKING);System.out.println("Connected " + socket);ByteBuffer bb = ByteBuffer.allocateDirect(32 * 1024).order(ByteOrder.nativeOrder());for (; ; ) {bb.limit(12);do {if (socket.read(bb) < 0)throw new EOFException();} while (bb.remaining() > 0);int length = bb.getInt(0);bb.limit(length);do {if (socket.read(bb) < 0)throw new EOFException();} while (bb.remaining() > 0);long now = System.nanoTime();try {//Running the date serialisation but this time inside the TCP callback.ByteArrayOutputStream out = new ByteArrayOutputStream();ObjectOutputStream oos = new ObjectOutputStream(out);oos.writeObject(date);ObjectInputStream ois = new ObjectInputStream(new ByteArrayInputStream(out.toByteArray()));date = (Date)ois.readObject();dateProbe.sampleNanos(System.nanoTime() - now);} catch (IOException | ClassNotFoundException e) {e.printStackTrace();}bb.flip();if (socket.write(bb) < 0)throw new EOFException();bb.clear();}} catch (IOException e) {e.printStackTrace();} finally {System.out.println("... disconnected " + socket);try {if (ssc != null)ssc.close();} catch (IOException ignored) {}try {if (socket != null)socket.close();} catch (IOException ignored) {}}}, "server").start();}@Overridepublic void run(long startTimeNs) {bb.position(0);bb.putInt(bb.remaining());bb.putLong(startTimeNs);bb.position(0);writeAll(socket, bb);bb.position(0);try {readAll(socket, bb);} catch (IOException e) {e.printStackTrace();}bb.flip();if (bb.getInt(0) != fixMessageBytes.length) {throw new AssertionError("read error");}lth.sample(System.nanoTime() - startTimeNs);}private static void readAll(SocketChannel socket, ByteBuffer bb) throws IOException {bb.clear();do {if (socket.read(bb) < 0)throw new EOFException();} while (bb.remaining() > 0);}private static void writeAll(SocketChannel socket, ByteBuffer bb) {try {while (bb.remaining() > 0 && socket.write(bb) >= 0) ;} catch (IOException e) {e.printStackTrace();}} }這次的結果如下所示:
Warm up complete (50000 iterations took 3.83s) -------------------------------- BENCHMARK RESULTS (RUN 1) ------------------------ Run time: 6.712s Correcting for co-ordinated:true Target throughput:20000/s = 1 message every 50us End to End: (100,000) 50/90 99/99.9 99.99 - worst was 822,080 / 1,509,950 1,711,280 / 1,711,280 1,711,280 - 1,711,280 date serialisation (100,000) 50/90 99/99.9 99.99 - worst was 11 / 19 31 / 50 901 - 2,420 OS Jitter (64,973) 50/90 99/99.9 99.99 - worst was 8.1 / 16 40 / 1,540 4,850 - 18,350 -------------------------------------------------------------------- -------------------------------- BENCHMARK RESULTS (RUN 2) --------- Run time: 6.373s Correcting for co-ordinated:true Target throughput:20000/s = 1 message every 50us End to End: (100,000) 50/90 99/99.9 99.99 - worst was 1,107,300 / 1,375,730 1,375,730 / 1,375,730 1,375,730 - 1,375,730 date serialisation (100,000) 50/90 99/99.9 99.99 - worst was 11 / 19 29 / 52 901 - 1,670 OS Jitter (40,677) 50/90 99/99.9 99.99 - worst was 8.4 / 16 34 / 209 934 - 1,470 -------------------------------------------------------------------- -------------------------------- BENCHMARK RESULTS (RUN 3) --------- Run time: 5.333s Correcting for co-ordinated:true Target throughput:20000/s = 1 message every 50us End to End: (100,000) 50/90 99/99.9 99.99 - worst was 55,570 / 293,600 343,930 / 343,930 343,930 - 343,930 date serialisation (100,000) 50/90 99/99.9 99.99 - worst was 9.0 / 16 26 / 38 770 - 1,030 OS Jitter (32,042) 50/90 99/99.9 99.99 - worst was 9.0 / 13 22 / 58 737 - 934 -------------------------------------------------------------------- -------------------------------- SUMMARY (end to end)--------------- Percentile run1 run2 run3 % Variation 50: 822083.58 1107296.26 55574.53 92.66 90: 1509949.44 1375731.71 293601.28 71.07 99: 1711276.03 1375731.71 343932.93 66.67 99.9: 1711276.03 1375731.71 343932.93 66.67 99.99: 1711276.03 1375731.71 343932.93 66.67 worst: 1711276.03 1375731.71 343932.93 66.67 -------------------------------------------------------------------- -------------------------------- SUMMARY (date serialisation )------ Percentile run1 run2 run3 % Variation 50: 11.01 11.01 8.96 13.22 90: 18.94 18.94 15.62 12.44 99: 31.23 29.18 26.11 7.27 99.9: 50.18 52.22 37.89 20.14 99.99: 901.12 901.12 770.05 10.19 worst: 2424.83 1671.17 1032.19 29.21 --------------------------------------------------------------------可以看出,相同的日期序列化從?4.5us到?10us的時間是原來的兩倍。
并不是在這里詳細討論為什么代碼在上下文中運行需要花費更長的時間,但這與在日期序列調用之間填充CPU緩存有關。
當我們運行時(如微型基準測試中一樣)是日期序列化,那么它可以很好地裝入CPU緩存中,而無需清除。 但是,當對日期序列化的調用之間存在間隙時,該操作的代碼將被清除并需要重新加載。
JLBH允許您在上下文中對代碼進行基準測試,這是延遲基準測試的重要組成部分。
翻譯自: https://www.javacodegeeks.com/2016/04/jlbh-examples-1-code-benchmarked-context.html
總結
以上是生活随笔為你收集整理的JLBH示例1 –为什么应在上下文中对代码进行基准测试的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 国土局官网查询(国土局备案查询)
- 下一篇: aspect spring_使用Aspe