在这篇文章中:
- 使用JLBH测试QuickFIX
- 观察QuickFix延迟如何通过百分位数降低
- 比较QuickFIX和Chronicle FIX
如JLBH简介中所述,创建JLBH的主要原因是为了测量Chronicle-FIX引擎。
我们使用了JLBH的所有功能,特别是吞吐量杠杆和协调遗漏的说明,以获取一些实际的QuickFIX时间。
在本文的后面,我们将看到ChronicleFIX的一些结果,但首先让我们看一下对FixFix的开源实现的基准测试。
这是我们将要进行基准测试的场景:
- 客户端创建一个NewOrderSingle,然后将其传递到服务器。
- 服务器解析NewOrderSingle
- 服务器创建一个ExecutionReport,该报告将发送回客户端。
- 客户端收到执行报告
从客户端开始创建NewOrderSingle到客户端收到ExecutionReport的时间开始计算端到端时间。
注意:我们需要在程序右边保留调用基准测试的开始时间。 为此,我们使用了一个技巧,并将开始时间设置为标签ClOrdId。
如果要在服务器上运行基准测试,则应克隆此GitHub存储库,所有jar和配置文件都在此处设置。
为了这篇文章,这里是基准测试的代码。
package org.latency.quickfix;
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 quickfix.*;
import quickfix.field.*;
import quickfix.fix42.ExecutionReport;
import quickfix.fix42.NewOrderSingle;
import java.util.Date;
import java.util.concurrent.Executors;
/**
* Created by daniel on 19/02/2016.
* Latency task to test sending a message in QuickFix
*/
public class QFJLBHTask implements JLBHTask {
private QFClient client;
private JLBH lth;
private static NewOrderSingle newOrderSingle;
private static ExecutionReport executionReport;
public static void main(String[] args) {
executionReport = new ExecutionReport();
executionReport.set(new AvgPx(110.11));
executionReport.set(new CumQty(7));
executionReport.set(new ClientID("TEST"));
executionReport.set(new ExecID("tkacct.151124.e.EFX.122.6"));
executionReport.set(new OrderID("tkacct.151124.e.EFX.122.6"));
executionReport.set(new Side('1'));
executionReport.set(new Symbol("EFX"));
executionReport.set(new ExecType('2'));
executionReport.set(new ExecTransType('0'));
executionReport.set(new OrdStatus('0'));
executionReport.set(new LeavesQty(0));
newOrderSingle = new NewOrderSingle();
newOrderSingle.set(new OrdType('2'));
newOrderSingle.set(new Side('1'));
newOrderSingle.set(new Symbol("LCOM1"));
newOrderSingle.set(new HandlInst('3'));
newOrderSingle.set(new TransactTime(new Date()));
newOrderSingle.set(new OrderQty(1));
newOrderSingle.set(new Price(200.0));
newOrderSingle.set(new TimeInForce('0'));
newOrderSingle.set(new MaturityMonthYear("201106"));
newOrderSingle.set(new SecurityType("FUT"));
newOrderSingle.set(new IDSource("5"));
newOrderSingle.set(new SecurityID("LCOM1"));
newOrderSingle.set(new Account("ABCTEST1"));
JLBHOptions jlbhOptions = new JLBHOptions()
.warmUpIterations(20_000)
.iterations(10_000)
.throughput(2_000)
.runs(3)
.accountForCoordinatedOmmission(false)
.jlbhTask(new QFJLBHTask());
new JLBH(jlbhOptions).start();
}
@Override
public void init(JLBH lth) {
this.lth = lth;
Executors.newSingleThreadExecutor().submit(() ->
{
QFServer server = new QFServer();
server.start();
});
Jvm.pause(3000);
client = new QFClient();
client.start();
}
@Override
public void complete() {
System.exit(0);
}
@Override
public void run(long startTimeNs) {
newOrderSingle.set(new ClOrdID(Long.toString(startTimeNs)));
try {
Session.sendToTarget(newOrderSingle, client.sessionId);
} catch (SessionNotFound sessionNotFound) {
sessionNotFound.printStackTrace();
}
}
private class QFServer implements Application {
void start() {
SocketAcceptor socketAcceptor;
try {
SessionSettings executorSettings = new SessionSettings(
"src/main/resources/acceptorSettings.txt");
FileStoreFactory fileStoreFactory = new FileStoreFactory(
executorSettings);
MessageFactory messageFactory = new DefaultMessageFactory();
FileLogFactory fileLogFactory = new FileLogFactory(executorSettings);
socketAcceptor = new SocketAcceptor(this, fileStoreFactory,
executorSettings, fileLogFactory, messageFactory);
socketAcceptor.start();
} catch (ConfigError e) {
e.printStackTrace();
}
}
@Override
public void onCreate(SessionID sessionId) {
}
@Override
public void onLogon(SessionID sessionId) {
}
@Override
public void onLogout(SessionID sessionId) {
}
@Override
public void toAdmin(Message message, SessionID sessionId) {
}
@Override
public void fromAdmin(Message message, SessionID sessionId)
throws FieldNotFound, IncorrectDataFormat, IncorrectTagValue,
RejectLogon {
}
@Override
public void toApp(Message message, SessionID sessionId) throws DoNotSend {
}
@Override
public void fromApp(Message message, SessionID sessionId)
throws FieldNotFound, IncorrectDataFormat, IncorrectTagValue,
UnsupportedMessageType {
try {
executionReport.set(((NewOrderSingle) message).getClOrdID());
Session.sendToTarget(executionReport, sessionId);
} catch (SessionNotFound invalidMessage) {
invalidMessage.printStackTrace();
}
}
}
private class QFClient implements Application {
private SessionID sessionId = null;
void start() {
SocketInitiator socketInitiator;
try {
SessionSettings sessionSettings = new SessionSettings("src/main/resources/initiatorSettings.txt");
FileStoreFactory fileStoreFactory = new FileStoreFactory(sessionSettings);
FileLogFactory logFactory = new FileLogFactory(sessionSettings);
MessageFactory messageFactory = new DefaultMessageFactory();
socketInitiator = new SocketInitiator(this,
fileStoreFactory, sessionSettings, logFactory,
messageFactory);
socketInitiator.start();
sessionId = socketInitiator.getSessions().get(0);
Session.lookupSession(sessionId).logon();
while (!Session.lookupSession(sessionId).isLoggedOn()) {
Thread.sleep(100);
}
} catch (Throwable exp) {
exp.printStackTrace();
}
}
@Override
public void fromAdmin(Message arg0, SessionID arg1) throws FieldNotFound,
IncorrectDataFormat, IncorrectTagValue, RejectLogon {
}
@Override
public void fromApp(Message message, SessionID arg1) throws FieldNotFound,
IncorrectDataFormat, IncorrectTagValue, UnsupportedMessageType {
long startTime = Long.parseLong(((ExecutionReport) message).getClOrdID().getValue());
lth.sample(System.nanoTime() - startTime);
}
@Override
public void onCreate(SessionID arg0) {
}
@Override
public void onLogon(SessionID arg0) {
System.out.println("Successfully logged on for sessionId : " + arg0);
}
@Override
public void onLogout(SessionID arg0) {
System.out.println("Successfully logged out for sessionId : " + arg0);
}
@Override
public void toAdmin(Message message, SessionID sessionId) {
boolean result;
try {
result = MsgType.LOGON.equals(message.getHeader().getField(new MsgType()).getValue());
} catch (FieldNotFound e) {
result = false;
}
if (result) {
ResetSeqNumFlag resetSeqNumFlag = new ResetSeqNumFlag();
resetSeqNumFlag.setValue(true);
((quickfix.fix42.Logon) message).set(resetSeqNumFlag);
}
}
@Override
public void toApp(Message arg0, SessionID arg1) throws DoNotSend {
}
}
}
这些是我看到的在服务器Intel®Xeon®CPU E5-2650 v2 @ 2.60GHz上运行的结果。
吞吐量为2,000 / s
Percentile run1 run2 run3 % Variation
50: 270.34 270.34 233.47 9.52
90: 352.26 335.87 1867.78 75.25
99: 6684.67 4849.66 69206.02 89.84
99.9: 13369.34 12845.06 163577.86 88.67
99.99: 81788.93 20447.23 163577.86 82.35
worst: 111149.06 98566.14 163577.86 30.54
吞吐量为10,000 / s
Percentile run1 run2 run3 % Variation
50: 184.32 176.13 176.13 0.00
90: 573.44 270.34 249.86 5.18
99: 19398.66 2686.98 5111.81 37.56
99.9: 28835.84 7733.25 7995.39 2.21
99.99: 30932.99 9699.33 9175.04 3.67
worst: 30932.99 9699.33 9175.04 3.67
平均值是〜200us,但是当您通过百分位数时,延迟确实开始降低。 这在很大程度上归因于所创建的垃圾量! 您可以通过使用jvm标志-verbosegc运行基准测试来查看此信息。 实际上,当您将吞吐量提高到50,000 / s时,甚至完全耗尽了第90个百分位数(每10个迭代中有1个),并且最终会延迟数毫秒。
吞吐量为50,00 / s
Percentile run1 run2 run3 % Variation var(log)
50: 176.13 176.13 176.13 0.00 11.82
90: 12845.06 29884.42 3604.48 82.94 21.01
99: 34603.01 94371.84 17301.50 74.81 25.26
99.9: 42991.62 98566.14 25690.11 65.41 25.84
99.99: 45088.77 98566.14 27787.26 62.94 25.93
worst: 45088.77 98566.14 27787.26 62.94 25.93
这里的问题不仅是平均时间(假设〜200us对您来说太慢了),而且更令人担忧的是,随着吞吐量的增加以及研究更高的百分位数,数字的降低方式。 让我们比较一下Chronicle-FIX。 该测试在完全相同的场景和同一台计算机上运行。
结果看起来像这样:
吞吐量为2000 / s
Percentile run1 run2 run3 % Variation
50: 16.90 16.90 16.90 0.00
90: 18.94 18.94 18.94 0.00
99: 26.11 30.21 23.04 17.18
99.9: 35.84 39.94 33.79 10.81
99.99: 540.67 671.74 401.41 65.41
worst: 638.98 1081.34 606.21 61.59
吞吐量为10,000 / s
Percentile run1 run2 run3 % Variation
50: 16.90 16.90 16.13 3.08
90: 18.94 18.94 18.94 0.00
99: 26.11 22.02 20.99 3.15
99.9: 88.06 33.79 83.97 49.75
99.99: 999.42 167.94 802.82 71.59
worst: 1146.88 249.86 966.66 65.67
吞吐量为50,000 / s
Percentile run1 run2 run3 % Variation
50: 15.62 15.10 15.62 2.21
90: 17.92 16.90 16.90 0.00
99: 22.02 30.21 29.18 2.29
99.9: 120.83 352.26 33.79 86.27
99.99: 335.87 802.82 96.26 83.03
worst: 450.56 901.12 151.55 76.73
Chronicle-FIX的平均值约为16us,比QuickFIX快12倍。 但这不仅仅因为几乎所有时间都在TCP往返中。 当您测量TCP时间时(请参阅最新发布的JLBH示例3 –吞吐量对延迟的影响 ),结果发现大部分时间是TCP〜10us。 因此,如果扣除TCP时间,就可以得到。
- QuickFix 200 – 10 = 190
- 编年史-16-10 = 6
- Chronicle-FIX比QF快30倍以上
正如已经证明的那样,如果您关心较高的百分位数,就会比这差得多。 为了完整起见,应该注意的是,作为基准测试的服务器噪声很大。 它的延迟峰值约为400us,这说明较高百分比中显示的数字更大。 此测试还使用环回TCP,这给Linux内核带来了巨大压力。 实际上,当您将吞吐量提高得很高时(会通过简单的TCP测试进行尝试)会发生奇怪的事情-因此,这不是测试Chronicle-FIX的最佳方法。 它仅用作与Quick FIX的比较。
使用Chronicle-FIX,如果您在调整的服务器上衡量将修复消息解析到其数据模型(包括日志记录)的过程中,则实际上会看到此概要文件已在10,000 / s至200,000 / s的吞吐量概要文件中进行了测试:
Percentile run1 run2 run3 run4 run5
50: 1.01 1.01 1.01 1.01 1.06
90: 1.12 1.12 1.12 1.12 1.12
99: 1.38 1.31 1.44 1.31 2.11
99.9: 2.88 2.88 2.88 2.88 4.03
99.99: 3.26 3.14 3.39 3.14 6.02
worst: 5.25 6.27 22.02 20.99 18.94
翻译自: https://www.javacodegeeks.com/2016/04/jlbh-examples-4-benchmarking-quickfix-vs-chroniclefix-2.html