Статьи

JLBH Примеры 4 — Сравнительный анализ QuickFix и ChronicleFix

Ноябрь 29, 2018

В этом посте:

  • Использование JLBH для тестирования QuickFIX
  • Наблюдение, как задержки QuickFix ухудшаются через процентили
  • Сравнение QuickFIX с Chronicle FIX

Как упоминалось во введении к JLBH, основной причиной создания JLBH было измерение двигателя Chronicle-FIX.

Мы используем все функции JLBH, в частности, рычаг пропускной способности и учет скоординированных пропусков, чтобы получить некоторые реалистичные временные характеристики для QuickFIX.

Позже в этой статье мы рассмотрим некоторые результаты для ChronicleFIX, но сначала давайте посмотрим на сравнительный анализ QuickFix с открытым исходным кодом для Fix Engine.

Это сценарий, который мы будем тестировать:

  • Клиент создает NewOrderSingle, который затем передается на сервер.
  • Сервер анализирует NewOrderSingle
  • Сервер создает ExecutionReport, который отправляется обратно клиенту.
  • Клиент получает ExecutionReport

Время до конца измеряется с момента, когда клиент начинает создавать NewOrderSingle, до момента, когда клиент получает ExecutionReport.

Примечание: нам нужно сохранить время начала, в которое тест был вызван при запуске программы. Для этого мы используем хитрость и устанавливаем время начала для тега ClOrdId.

Если вы хотите, чтобы тест выполнялся на ваших серверах, вы должны клонировать этот репозиторий GitHub, в котором все jar-файлы и файлы конфигурации находятся там.

Ради этого поста вот код для теста.

001
002
003
004
005
006
007
008
009
010
011
012
013
014
015
016
017
018
019
020
021
022
023
024
025
026
027
028
029
030
031
032
033
034
035
036
037
038
039
040
041
042
043
044
045
046
047
048
049
050
051
052
053
054
055
056
057
058
059
060
061
062
063
064
065
066
067
068
069
070
071
072
073
074
075
076
077
078
079
080
081
082
083
084
085
086
087
088
089
090
091
092
093
094
095
096
097
098
099
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
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 (R) Xeon (R) CPU E5-2650 v2 @ 2.60GHz.
Пропускная способность 2000 / с

1
2
3
4
5
6
7
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

При пропускной способности 10000 / с

1
2
3
4
5
6
7
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

Среднее значение составляет ~ 200 мкс, но по мере прохождения процентилей задержки действительно начинают ухудшаться. Во многом это связано с количеством создаваемого мусора! Вы можете увидеть это, запустив тест с флагом jvm -verbosegc. Фактически, когда вы увеличиваете пропускную способность до 50 000 / с, даже ваш 90-й процентиль (1 на каждые 10 итераций) полностью уносится, и вы в конечном итоге сталкиваетесь с задержками в несколько миллисекунд.

При пропускной способности 50,00 / с

1
2
3
4
5
6
7
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

Проблемы здесь не только в среднем времени (при условии, что ~ 200 мс слишком медленны для вас), но еще более тревожно в том, как ухудшаются числа при увеличении пропускной способности и при изучении более высоких процентилей. Давайте сравним эту хронику-FIX. Тест выполняется для точно такого же сценария и на той же машине.
Результаты выглядят так:

Пропускная способность 2000 / с

1
2
3
4
5
6
7
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

При пропускной способности 10000 / с

1
2
3
4
5
6
7
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

При пропускной способности 50000 / с

1
2
3
4
5
6
7
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, что в 12 раз быстрее, чем QuickFIX. Но это еще не все, потому что почти все это время идет по протоколу TCP. Когда вы измеряете время TCP (см. Последний пост Примеры JLBH 3 — Влияние пропускной способности на задержку ), оказывается, что большую часть этого времени составляет TCP ~ 10us. Поэтому, если вы вычитаете TCP раз, вы получаете.

  • QuickFix 200 — 10 = 190
  • Хроника-FIX 16 — 10 = 6
  • Chronicle-FIX более чем в 30 раз быстрее, чем QF

И как было продемонстрировано, если вы заботитесь о своем верхнем процентиле, чем это становится намного хуже, чем это. Для полноты следует отметить, что сервер, на котором это тестировалось, был достаточно шумным. У него были пики задержки около 400 мкс, что объясняет большие цифры, которые отображаются в более высоких процентилях. Кроме того, в этом тесте используется петлевой TCP, который сильно нагружает ядро ​​Linux. На самом деле странные вещи случаются, когда вы действительно повышаете пропускную способность (вы можете попробовать это с помощью простого теста TCP) — так что это не лучший способ проверить Chronicle-FIX. Он используется только для сравнения с Quick FIX.

Используя Chronicle-FIX, если вы измеряете синтаксический анализ сообщения исправления в его модели данных, включая ведение журнала, на настроенном сервере, вы фактически видите этот профиль проверенным для профилей пропускной способности от 10000 / с до 200 000 / с:

1
2
3
4
5
6
7
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
Ссылка: Примеры 4 JLBH — Сравнительный анализ QuickFix и ChronicleFix от нашего партнера JCG Дэниела Шая в блоге Rational Java .
37
Share: