開発者の手記 #3 — cBotのバグを減らすために「ログ出力」を徹底した話

拓海だ。前回と前々回は「時間軸」と「インジケーター計算」の話をした。今回は、それらのバグを見つけるために必須の「ログ出力」について書く。

ブラックボックスのcBotロジック

cBotを動かしていると、バックテスト結果と実運用で成績が違う、シグナルが出たはずなのに注文されない、ストップロスが想定より広い…こんな現象に引っかかる。

原因を調べようにも、cBotの内部動作は目に見えない。OnBar()が何回実行されたのか、インジケーターの値は実際いくつだったのか、注文の状態遷移はどうなってるのか。推測で進めると、余計な時間がかかる。

自分も最初はそうだった。何か変だと感じても「どこが変なのか」を特定するのに、数日かかることもあった。

ログ出力で「見える化」する

ターニングポイントは、ある先輩から「ログ出力を徹底しろ」と言われたことだ。当時の自分は「ログなんて本番環境の話じゃん」と思ってた。だが、その先輩はcBotの開発中から、重要な部分にログを仕込んでた。

具体的には:

これをやると、バックテスト結果を見たときに「あ、ここで実行されてなかったんだ」とか「インジケーター値がこんなに違うのか」とか、一目瞭然になる。

実装例:OnBar()の実行タイミング

自分がこれで引っかかったのは「OnBar()が想定より遅く実行される」という現象。M5足でエントリーシグナルを判定してるのに、なぜか実行が遅れてる気がした。

ログを仕込んでみたら、こんな出力が出た:

[14:05:30.123] OnBar executed - Symbol: EURUSD, TimeFrame: M5
[14:10:45.567] OnBar executed - Symbol: EURUSD, TimeFrame: M5

あ、5分ごとじゃなくて、次のbar始値が来たタイミングで実行されてる。これは前回の記事で書いた「bar確定の遅延」そのもの。ログで確認できたから、対策を立てられた。

インジケーター値の検証

もう1つ。前回の記事で「RSIの計算方法がプラットフォーム間で違う」と書いたが、これもログで検証した。

cBot内で RSI を計算して、ログに出力。同じタイミングで TradingView の RSI と比較。すると「あ、値が違う」と確認できる。

これで初めて「cTrader のライブラリを使ってるから値が違うんだ」と納得できた。推測じゃなくて、データで確認できるのは強い。

注文状態のトレース

もっと重要なのが「注文状態の遷移」だ。

エントリーしたはずなのに、決済されてないのに、なぜかポジションがない…みたいな現象に引っかかることがある。

ログを仕込むと:

[14:15:20] Entry signal detected - Price: 1.0850, ATR: 0.0045
[14:15:20] Placing order - Volume: 0.1, SL: 1.0805, TP: 1.0895
[14:15:22] Order placed - OrderId: 12345, Status: Pending
[14:16:00] Order cancelled - Reason: Timeout

あ、注文が Pending で残ってて、タイムアウトで自動キャンセルされてた。こういう事実を知らないと、ロジックの改善のしようがない。

本番環境でもログは必須

今は、本番環境でもログを出力してる。ファイルに保存するなり、クラウドに送信するなり。

理由は「バックテストと実運用の差分を追いやすいから」。バックテストではうまくいくのに、実運用で成績が落ちる…こんなときに、ログがあると原因特定が格段に速い。

自分の場合、最近も「スプレッドの変動で想定より SL が狭くなってる」ことに気づいたのは、ログのおかげ。ログなかったら、多分ずっと気づかなかった。

まとめ

cBotの開発で「ログ出力を徹底する」。これは、時間軸やインジケーター計算の問題を見つけるための必須スキルだ。

最初は「ログなんて面倒」と思ってたが、今は「ログなしで開発するなんて考えられない」と思ってる。バグ原因の特定時間が劇的に短くなるし、本番環境での問題も早期発見できる。

これからcBot開発を始める人は、最初からログ出力を習慣にしておくことをお勧めする。

本記事は一般的な情報提供を目的としています。投資助言ではありません。 取引判断はご自身の責任で行ってください。