トレーディングシステム開発・調査メモ (2)

2018年12月9日 9:18

だいたい16分で読めます

investment

Table of Contents

Top
仮説2-2: 数秒でクローズしているのは、タイムラグによって乖離した価格で約定していることが原因である
詳細なデータ
簡単な調査
詳細な調査
結論2-2
仮説3: BF WebSocketからのデータは75%以上の割合で500ms以上遅延する
計測方法
計測結果
結論3
仮説4: IFD注文では、正常時の取引所でも約定まで必ず1秒以上遅延する
データ集め
結論4
まとめ

引き続き、botの挙動で気になった箇所を調査してゆきます。
前回記事はこちら。

今回は遅延の計測がメインです。

仮説2-2: 数秒でクローズしているのは、タイムラグによって乖離した価格で約定していることが原因である

前回の宿題です。

前回記事のMotivating Exampleの情報を整理します。

ローカルの価格データは 477018〜476834付近（スプレッド180円程度）
2018-12-02 01:39:27 UTC にオーダーが受け付けられた
約2秒後（2018-12-02 01:39:28.873 UTC）に約定
オープンの約定価格は482126.0
クローズは3秒後（2018-12-02 01:39:31.763）、482311と482283で約定

詳細なデータ

オープンした約定データです。約定価格が482126.0となっています。

{
    "id": 613460271,
    "side": "BUY",
    "price": 482126,
    "size": 0.02,
    "exec_date": "2018-12-02T01:39:28.873",
    "child_order_id": "JFX20181202-013928-512467F",
    "commission": 0,
    "child_order_acceptance_id": "JRF20181202-013927-012822"
}

こちらはクローズ。

{
    "id": 613460418,
    "side": "SELL",
    "price": 482311,
    "size": 0.01,
    "exec_date": "2018-12-02T01:39:31.763",
    "child_order_id": "JFX20181202-013931-517900F",
    "commission": 0,
    "child_order_acceptance_id": "JRF20181202-013927-012831"
},
{
    "id": 613460419,
    "side": "SELL",
    "price": 482283,
    "size": 0.01,
    "exec_date": "2018-12-02T01:39:31.763",
    "child_order_id": "JFX20181202-013931-517900F",
    "commission": 0,
    "child_order_acceptance_id": "JRF20181202-013927-012831"
},

簡単な調査

詳細は約定価格の履歴を漁らないといけないですが、まずは簡単に調べられる1分足データを使ってみます。Trading Viewで当時のローソクを見てみました。

安値: 480860 、高値: 482761

たしかに安値高値の間に入っています。その価格で配信されていたのは間違いないでしょう。

詳細な調査

当時BFが示したbid/askが必要です。これは約定履歴から確認する必要があります。約定履歴をひたすらfetchしてDBに放り込むPythonツールを利用し、下記のような出力が得られました。

ちゃんと履歴がありますね。 近辺の価格を見ても大きく乖離はしていない ようです。ではオーダーが受け付けられた約2秒前（ 2018-12-02 01:39:27 UTC ）、またオーダーをbotから送ったであろう4秒程度前、WebSocketからデータが送られたであろう6秒程度前ではどうだったのでしょうか？

約2秒前（01:39:27.000）
- bid: 481827 （2018-12-02 01:39:26.450000）
- ask: 482211（2018-12-02 01:39:26.997000）
約4秒前（01:39:25.000）
- bid: 481796 （2018-12-02 01:39:24.950000）
- ask: 481849 （2018-12-02 01:39:24.997000）
約6秒前（01:39:23.000）
- bid: 481499 （2018-12-02 01:39:22.920000）
- ask: 481630 （2018-12-02 01:39:22.873000）

6秒前まで遡っても、 477018〜476834 とは4,000近く差のある価格になっていました。
実際、477018を切る価格だったのは 01:31:42.950000 、実に8分弱前です。
WebSocketからの価格データが遅延したとは考えにくい長さです。

このことから、ローカルで持っている価格データがおかしかったと考えられます。価格データのログを出していなかったため、これ以上の調査はできませんでした。また発生したら調べたいと思います。

結論2-2

数秒でクローズしている原因はタイムラグだけではない。

Motivating Exampleにあるような5000円以上の乖離は無かった。約定履歴とWebSocketから配信されているデータが正しいとすると、botにバグがあることになる。再現した時点で再度検証する。

仮説3: BF WebSocketからのデータは75%以上の割合で500ms以上遅延する

仮説1の中で、BitFlyerのWebSocketからの価格データがかなり遅延している可能性が浮かびました。データが遅れると動きが鈍くなり、トリガーの精度低下やSL/TPの設定がおかしくなる現象を招きます。

ネットワーク遅延があるため一定のオーバーヘッドはありますが、500ms以上あると遅延していると仮定し、サーバーの状態が良くても発生しているのではないか？ということを調べてみます。

計測方法

下記のプログラムをGCPのasia-northeast1で数時間動かします。軽量なので、インスタンスはf1-microにしています。

10メッセージに1回遅延を計測し、外部ファイルに吐き出しています。
ここでの遅延の定義は、約定履歴メッセージに含まれる時刻データと受け取った時点での時刻の差分です。

頃合いを見てこのデータをローカルにダウンロードし、箱ひげ図にプロットしました。

計測結果

約20時間動かし、46359データが得られました。単位はmsです。

おっと、外れ値があまりに外れているので何もわからないグラフになってしまいました。一つ飛び出ているデータを削っても似たようなグラフになったので、数値で見てみましょう。

46359 rows
  2018-12-04 21:47:51 - 2018-12-05 17:13:29
count    46359.000000
mean       184.676228
std        398.884247
min        -80.261000
25%         76.384500
50%        105.105000
75%        181.621000
max      28782.979000

マ、マイナスぅ！？ 考えられる原因は以下ですが、1番が普通にありそうなのが怖いところですね……。

BFが未来の時刻で配信している
計測プログラムにバグがある
時折光の速さを超えた配信がされている

最大遅延は28.7秒、最小遅延は-80msというトンデモな結果になりましたが、75%で見れば181msと当初の仮説より優秀な結果になりました。不安定な時はとことんおかしくなる類のシステムに見受けられます。

念の為計測時間を考慮した算出もしてみましたが、特に結果に影響はありませんでした。

結論3

仮説3: BF WebSocketからのデータは75%以上の割合で500ms以上遅延する

計測したところ、75%の割合では181ms程度だった。

計測ツールにバグがないとすると、配信されているデータの信頼性が疑わしい時がある。

仮説4: IFD注文では、正常時の取引所でも約定まで必ず1秒以上遅延する

またしても、前回調査で発見された問題です。取引開始時（IFD注文）、実際に約定するまで2〜4秒程度の遅延がありました。ここでは、毎回それが発生しているかどうかを調べます。

データ集め

これは、今までの約定データを使えば簡単に調査できます。まず下記のようなParent Order一覧を取得します（ /v1/me/getparentorders ）。

{
    "id": 141298782,
    "parent_order_id": "JCP20181204-033429-568254",
    "product_code": "FX_BTC_JPY",
    "side": "BUYSELL",
    "parent_order_type": "IFDOCO",
    "price": 0,
    "average_price": 428902,
    "size": 0.03,
    "parent_order_state": "COMPLETED",
    "expire_date": "2018-12-11T02:14:29.057",
    "parent_order_date": "2018-12-04T03:34:29.057",
    "parent_order_acceptance_id": "JRF20181204-033429-761002",
    "outstanding_size": 0,
    "cancel_size": 0,
    "executed_size": 0.02,
    "total_commission": 0
}

この parent_order_id を使い、 '/v1/me/getchildorders から対応する注文を引いてきます。TP/SLによる約定結果も含めて返ってくるため、最後の要素だけ使用します。

[
    {
        "id": 740343317,
        "child_order_id": "JFX20181204-033457-094572F",
        "product_code": "FX_BTC_JPY",
        "side": "BUY",
        "child_order_type": "MARKET",
        "price": 0,
        "average_price": 429188,
        "size": 0.01,
        "child_order_state": "COMPLETED",
        "expire_date": "2018-12-11T02:14:29",
        "child_order_date": "2018-12-04T03:34:43",
        "child_order_acceptance_id": "JRF20181204-033429-568286",
        "outstanding_size": 0,
        "cancel_size": 0,
        "executed_size": 0.01,
        "total_commission": 0
    },
    {
        "id": 740342477,
        "child_order_id": "JFX20181204-033439-068825F",
        "product_code": "FX_BTC_JPY",
        "side": "SELL",
        "child_order_type": "MARKET",
        "price": 0,
        "average_price": 428616,
        "size": 0.01,
        "child_order_state": "COMPLETED",
        "expire_date": "2018-12-11T02:14:29",
        "child_order_date": "2018-12-04T03:34:29",
        "child_order_acceptance_id": "JRF20181204-033429-568263",
        "outstanding_size": 0,
        "cancel_size": 0,
        "executed_size": 0.01,
        "total_commission": 0
    }
]

最後に、この child_order_id を使って /v1/me/getexecutions から約定時間を取ってくれば完了です。

{
    "id": 619456202,
    "side": "SELL",
    "price": 428616,
    "size": 0.01,
    "exec_date": "2018-12-04T03:34:39.583",
    "child_order_id": "JFX20181204-033439-068825F",
    "commission": 0,
    "child_order_acceptance_id": "JRF20181204-033429-568263"
}

この例ですと、以下のように遅延が計算できます。

親注文受付: 2018-12-04T03:34:29.057 （getparentorders から "parent_order_date"）
小注文発注: 2018-12-04T03:34:29 （getchildorders から "child_order_date"）
小注文約定: 2018-12-04T03:34:39.583 （getexecutions から "exec_date"）

あちゃー、発注から約定まで10秒遅延してますね……。成行とは思えません。

算出方法は分かったので、簡単なプログラムを書いて直近100件の注文における遅延を出してみます。

上からデータを見ていくと、「 やっぱり遅延が出てますね……あれ、結構短いなぁ……マ、マイナスぅ！？ 」と、楽しい気分になること請け合いです。マイナスは妙ですが、仮説3のWSでも見受けられたのでそういうものかもしれません。今回はまだ、DBが分散していたり、書き込み遅延があると考えれば説明が付きそうです。何にせよ配信データを過信すべきではありません。

さて、箱ひげ図にしてみると以下のようになります。

外れ値として20秒近い遅延はありますが、中央値はほぼ1秒です。データの連続性を鑑みると、 取引所の状態による影響が非常に大きい と考えられます。取引所の状態は記録されていないため正確なことは分かりませんが、損失に影響がありそうであれば、機会を見て調べてみたいと思います。

            delay
count  100.000000
mean     4.870090
std      7.284449
min     -0.000581
25%      0.000242
50%      1.000096
75%      7.000057
max     26.999897
median 1.000096

結論4

仮説4: IFD注文では、正常時の取引所でも約定まで必ず1秒以上遅延する

直近100回では、50%近い注文が1秒以内に約定しており、必ず1秒以上遅延するとは言えない。

損失との関係はまだ調査していないが、expireを短くすることで遅れた注文を切ると良いかもしれない。

まとめ

今回も本質的な損失を減らす調査にはなりませんでしたが、botを作る上で考慮すべき必要があるので良しとします。

次回は、今回分かった遅延への対策を考えます。例えば、以下のような仮説を扱う予定です。

親注文より子注文の方が速く約定するのでは？
WSからの遅延が大きい時に新規注文を止めれば損失が減るのでは？