ＭＴ４用ＥＡ開発時代 － 「OrderSelect問題」調査２（新たな仮説）

さて前回は、テスト中にも関わらずＭＴ４用ＥＡ共通部品「ahfw」ベータ版リリースのお知らせをしたところまで書きました。今回は、「OrderSelect問題」調査中に判った新たな仮説について書いてみたいと思います。

ただ、断言できる程の強い証拠ではありません。。

まず、「OrderSelect問題」で共通部品上ちょっと変わった使い方をしていたので、そこを疑って見た。何かと言うと、決済ロジックのOrderSelect()ループ内で、エラーを検出していた場合、OrderSelect(SELECT_BY_TICKET)した後の、OrderCloseTime()がゼロでなければOrderClose()を成功扱いにするという箇所。

普通に考えたら問題無いんだけど、念のための確認というレベル。

【検証方法／結果】

－－－－－－－－－－－－－－－－－－－－－－－－－－－－－

ポジション保有中に、OrderSelect()ループ内で決済処理後、決済されたかどうかを確認する為に、OrderCloseTime()がゼロじゃない事を確認する方法で、本当に改めてOrderSelect(SELECT_BY_TICKET)しなおさないといけないのか検証してみた。

パターン１．決済成功後OrderCloseTime()を出力

　　　　　　→　OrderCloseTime()がゼロ

パターン２．決済成功後、RefreshRates()がTRUEなってから、OrderCloseTime()を出力

　　　　　　→　OrderCloseTime()がゼロ

パターン３．RefreshRates()せずに、OrderSelect(SELECT_BY_TICKET)した後に、

　　　　　　　　OrderCloseTime()を出力

　　　　　　→　OrderCloseTime()が変化（ゼロじゃない値）

つまるところ、RefreshRates()するだけでは既にOrderSelect()していた後の値は最新化されず、OrderSelect()しなおせば最新化される。少なくともオーダ操作が成功していれば、RefreshRates()は不用。

－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－

【検証ソース（パターン３）】

－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－

#property copyright "Copyright  2011, ahaha_fxtrader"

#property link      "http://blog.livedoor.jp/ahaha_fxtrader/"

#include <stdlib.mqh>

#include <stderror.mqh>

//---- input parameters

extern int      Magic = 47982738;

extern int       SleepTime=2000;

int init()

{

    MathSrand(TimeCurrent());   

   return(0);

}

int deinit()

{

   return(0);

}

int start()

{

    static int ticket = 0;

    bool found = FALSE;

    datetime st;

    

    if( ticket<=0 )

    {

        int type = MathRand()-(32767.0/2.0);

        if( type >=0 )

        {

            st = TimeCurrent();

            ticket = OrderSend(Symbol(),OP_BUY,MarketInfo(Symbol(),MODE_MINLOT),Ask,10,0,0,NULL,Magic);

            if( ticket>0 ) 

            {

                Print("[[ORDER]] Symbol("+Symbol()+") Ticket("+ticket+")");

                Print("[[TIME]]Send:StartTimeCurrent("+st+") EndTimeCurrent("+TimeCurrent()+")");

            }

        }

        else

        {

            st = TimeCurrent();

            ticket = OrderSend(Symbol(),OP_SELL,MarketInfo(Symbol(),MODE_MINLOT),Bid,10,0,0,NULL,Magic);

            if( ticket>0 )

            {

                Print("[[ORDER]] Symbol("+Symbol()+") Ticket("+ticket+")");

                Print("[[TIME]]Send:StartTimeCurrent("+st+") EndTimeCurrent("+TimeCurrent()+")");

            }

        }

    }

    if( ticket<=0 ) return(0);

    

    // オーダ一覧取得ループ

    found = FALSE;

    for( int i=OrdersTotal()-1 ; i>=0 ; i-- )

    {

        // オーダ情報取得

        if( OrderSelect(i,SELECT_BY_POS , MODE_TRADES)==FALSE ) 

        {

            int Errno = GetLastError();

            RefreshRates();

            continue;

        }

         // 対象外であれば次

        if( (OrderMagicNumber() != Magic) || (OrderSymbol() != Symbol()) ) continue;

        

        // 一定時間スリープする

        Sleep(SleepTime);

        

        // チャートのシンボルとOrderSelectのシンボルを出力する

        if( (OrderSymbol()==Symbol()) && (ticket==OrderTicket()) ) Print("[[INFO]] Symbol("+Symbol()+") OrderSymbol("+OrderSymbol()+") Ticket("+ticket+") OrderTicket("+OrderTicket()+")");

        else Print("[[WARN]] Symbol("+Symbol()+") OrderSymbol("+OrderSymbol()+") Ticket("+ticket+") OrderTicket("+OrderTicket()+")");

        st=TimeCurrent();

        if( OrderClose(OrderTicket(),OrderLots(),OrderClosePrice(),100) )

        {

            if( OrderSelect(OrderTicket(),SELECT_BY_TICKET)==TRUE )

            {

                Print("[[CLOSE]] Symbol("+Symbol()+") OrderSymbol("+OrderSymbol()+") Ticket("+ticket+") OrderTicket("+OrderTicket()+") OrderCloseTime("+OrderCloseTime()+")");

                Print("[[TIME]]Close:StartTimeCurrent("+st+") EndTimeCurrent("+TimeCurrent()+")");

            }

            else Print("[[CLOSE]][INFO] OrderSelect(SELECT_BY_TICKET) Failed.Symbol("+Symbol()+") OrderSymbol("+OrderSymbol()+") Ticket("+ticket+") OrderTicket("+OrderTicket()+") OrderCloseTime("+OrderCloseTime()+")");

            ticket = 0;

        }

    }

    

   return(0);

}

－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－

★★★　以下の内容は誤り。詳細はコメントを参照ください　★★★

ただ、この「パターン３」の検証過程で問題が発生。

「OrderSelect問題」調査用ＥＡだから、シンボルとチケット番号がOrderSelect()結果と一致しているかどうかを確認するロジックがあるけど、なぜだか不一致が発生。

内容としては、関数内にstatic定義している変数ticketがOrderSelectループ中にゼロに。

上記ロジックの通り、ticketがゼロ以下であればOrderSelect()に入らない様になってるのに。

そして、後２回ＭＴ４を再起動してもう一度再現させようとしたら再現しなくなった。

以下が、問題発生時のログ出力結果の抜粋。

【ログ出力結果抜粋】

－－－－－－－－－－－－－－－－－－－－－－－

以前の検証と同じ設定（４通貨ペア）で実施したが、発生した通貨ペアはEURUSDのみ。

以下のログは、発生したEURUSDのみを抜粋。

02:53:19 XTestOrderSelect EURUSDfxf.,H4: open #5638297 buy 0.01 EURUSDfxf. at 1.4290 ok

02:53:19 XTestOrderSelect EURUSDfxf.,H4: [[ORDER]] Symbol(EURUSDfxf.) Ticket(5638297)

02:53:19 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Send:StartTimeCurrent(1308365599) EndTimeCurrent(1308365599)

02:53:30 XTestOrderSelect EURUSDfxf.,H4: [[INFO]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638297) OrderTicket(5638297)

02:53:40 XTestOrderSelect EURUSDfxf.,H4: [[INFO]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638297) OrderTicket(5638297)

02:53:41 XTestOrderSelect EURUSDfxf.,H4: close #5638297 buy 0.01 EURUSDfxf. at 1.4290 at price 1.4287

02:53:41 XTestOrderSelect EURUSDfxf.,H4: [[CLOSE]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638297) OrderTicket(5638297) OrderCloseTime(1308365620)

02:53:41 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Close:StartTimeCurrent(1308365619) EndTimeCurrent(1308365620)

02:53:51 XTestOrderSelect EURUSDfxf.,H4: [[WARN]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(0) OrderTicket(5638264)

02:53:53 XTestOrderSelect EURUSDfxf.,H4: open #5638307 buy 0.01 EURUSDfxf. at 1.4292 ok

02:53:53 XTestOrderSelect EURUSDfxf.,H4: [[ORDER]] Symbol(EURUSDfxf.) Ticket(5638307)

02:53:53 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Send:StartTimeCurrent(1308365632) EndTimeCurrent(1308365632)

02:54:03 XTestOrderSelect EURUSDfxf.,H4: [[INFO]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638307) OrderTicket(5638307)

02:54:03 XTestOrderSelect EURUSDfxf.,H4: close #5638307 buy 0.01 EURUSDfxf. at 1.4292 at price 1.4289

02:54:03 XTestOrderSelect EURUSDfxf.,H4: [[CLOSE]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638307) OrderTicket(5638307) OrderCloseTime(1308365643)

02:54:03 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Close:StartTimeCurrent(1308365642) EndTimeCurrent(1308365642)

02:54:12 XTestOrderSelect EURUSDfxf.,H4: [[WARN]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(0) OrderTicket(5638264)

02:54:15 XTestOrderSelect EURUSDfxf.,H4: open #5638314 buy 0.01 EURUSDfxf. at 1.4292 ok

02:54:15 XTestOrderSelect EURUSDfxf.,H4: [[ORDER]] Symbol(EURUSDfxf.) Ticket(5638314)

02:54:15 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Send:StartTimeCurrent(1308365654) EndTimeCurrent(1308365654)

02:54:25 XTestOrderSelect EURUSDfxf.,H4: [[INFO]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638314) OrderTicket(5638314)

02:54:25 XTestOrderSelect EURUSDfxf.,H4: close #5638314 buy 0.01 EURUSDfxf. at 1.4292 at price 1.4289

02:54:25 XTestOrderSelect EURUSDfxf.,H4: [[CLOSE]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638314) OrderTicket(5638314) OrderCloseTime(1308365665)

02:54:25 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Close:StartTimeCurrent(1308365664) EndTimeCurrent(1308365665)

02:54:33 XTestOrderSelect EURUSDfxf.,H4: [[WARN]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(0) OrderTicket(5638264)

02:54:36 XTestOrderSelect EURUSDfxf.,H4: open #5638317 sell 0.01 EURUSDfxf. at 1.4289 ok

02:54:36 XTestOrderSelect EURUSDfxf.,H4: [[ORDER]] Symbol(EURUSDfxf.) Ticket(5638317)

02:54:36 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Send:StartTimeCurrent(1308365675) EndTimeCurrent(1308365675)

02:54:45 XTestOrderSelect EURUSDfxf.,H4: [[INFO]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638317) OrderTicket(5638317)

02:54:47 XTestOrderSelect EURUSDfxf.,H4: close #5638317 sell 0.01 EURUSDfxf. at 1.4289 at price 1.4292

02:54:47 XTestOrderSelect EURUSDfxf.,H4: [[CLOSE]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(5638317) OrderTicket(5638317) OrderCloseTime(1308365686)

02:54:47 XTestOrderSelect EURUSDfxf.,H4: [[TIME]]Close:StartTimeCurrent(1308365685) EndTimeCurrent(1308365686)

02:54:49 XTestOrderSelect EURUSDfxf.,H4: [[WARN]] Symbol(EURUSDfxf.) OrderSymbol(EURUSDfxf.) Ticket(0) OrderTicket(5638264)

－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－

こんな感じで、"[[WARN]]"が都合４回発生。ただ、同じEURUSDでも発生しないケースもある。

そして、"[[WARN]]"の行で表示されているOrderTicket()の値は、ＥＡ開始前に残っていた同じチケット番号。なので、最初は２回クローズするしticketの値もゼロになるだろうけど、その後ずっとOrderTicket()の値が変わらず。 



ともかく、挙動不審。 

そして、４通貨ペアのスリープ時間の設定を再掲すると。

●スリープ時間（単位はミリ秒）

　EURUSD:10000

　USDCHF:2000

　GBPUSD:5000

　USDJPY:3000

つまり、一番スリープ時間が長い通貨ペアで発生した。

発生した時はログ採取時間は２分程度。

そして、ＭＴ４再起動＆ＥＡ再実行を、７分間と６分間の２回実行しても再発しない。

その２回とは、ＥＡ開始前にポジションを残しておくケースと、残しておかないケース。

ここで新たな仮説が。

＃またトンデモ仮説かも。。。

【新たな仮説】

－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－

上記プログラム・ソース、守っていないルールが１つある。それが、以下のヘルプの箇所。

●参照：特殊関数【Special functions】

●抜粋

　「It is not recommended to call start() function from init() function or to perform trade 

　　operations, as chart data, market prices, etc. can be incomplete by the moment of 

　　the module initialization. The init() and deinit() functions must finish their working 

　　as soon as possible and, in no case, shall they loop when trying to start its 

　　full-fledged working before the start() function is called.

　　init() 関数から start() 関数を呼び出したり、トレード操作をすことは推奨できません。

　　モジュール初期化の最中は、チャートデータや市場価格が不完全である場合があります。

　　init() と deinit() 関数は出来るだけ早く動作を終了する必要があります。そして、

　　start() 関数が呼び出される前に、その完全な動作を完了し、始めようとするとき処理中

　　である場合はあり得ません。」

ヘルプ上の表現では、「start()が呼びだされる前にinit()/deinit()を終らせろ」という事みたいなんだけど、ティックデータ受信用のパスが直ぐに開通して、すぐにティックデータを受信したら、init()関数内をいくら軽くしたところで、逆転してしまう可能性を秘めているという事なので、自分で制御しないといけない。

つまり、init()が完了する前に、start()が開始してはいけないというルール。

このルールは途中で気付いてinit()完了前にstart()に入ってきたらそのままリターンするロジックを組み込んだ。

そして、改めて「OrderSelect問題」発生時のソースを見てみると、そのロジックは入っていない。

なので、以下の仮説

●仮説内容

　安定した状態で起動する時と、不安定な状態で起動する事がある。

　具体的には、init()完了前にstart()でOrderSelect()すると以降不安定になる。

●仮説理由

　・init()完了確認ロジックが入っていない状態で似た現象が発生。

　・ＭＴ４を起動し直すと再発しなくなった。

　・不安定な状況では、OrderSelect()が正しく機能していない

　・OrderSelect()が正しく機能していないのはスリープ時間が一番長い通貨ペア

－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－－

ちなみに、再現させた環境は以下。

【再現した環境】

－－－－－－－－－－－－－－－－－－－－－－－

ＯＳ：Windows7 Home Premium(64bit)

メモリ：８Ｇ

MetaTrader4：FOREX.com Japan Version:4.00 Build 229(26 Nov 2010)

－－－－－－－－－－－－－－－－－－－－－－－

じゃあ、今後どうするのかという話。

【今後調査をどうするのか】

－－－－－－－－－－－－－－－－－－－－－－－－－－

で、証拠として弱い点としては、最初に「OrderSelect問題」が発生した時のＯＳがＸＰで異なるＰＣであるという事と、少なくともFOREX.comではWindows7はサポートしていない点。

そして、証拠が状況証拠レベルな事。

もうちょっと証拠を積み上げるとすると、以下の検証方法が考えられる。

案１．何回も再起動させる

　　　start()関数内でinit()完了してなければその旨をログ出力して、事象が発生した時に、

　　　そのログが出力されてなければ仮説が否定された事になる。実施環境はＸＰの環境。

　　　ちょっと時間かかりそう。。

案２．start()関数の排他制御を外す

　　　この仮説が正しければ、処置済みという事なので、start()関数の排他制御を外しても

　　　再発しないはずという考え方。再発したらすぐに白黒はっきりする。

　　　ただ、これをするには、前回記事の「ファイル上への大域変数保存でのリトライ検討」と、

　　　「start()関数直後のIsTradeAllowed()チェック要否検討」してからにしたい。

　　　どっちにしても、元々しなきゃいけない事だから作業量は変わらないけど。

●結論

　こればっかりに時間掛けてられないし、「案２．」で検証することに。

　それより、本来の「テスト計画」に基づくテストを開始するために、

　他の課題と、ドキュメントを書くほうを優先させる。

－－－－－－－－－－－－－－－－－－－－－－－－－－

信じるか信じないかは、

あなた次第です。

＃でもコメント欲しいなぁ。。

★★★　誤り箇所ここまで。信じてはいけません。　★★★

【お知らせ】

－－－－－－－－－－－－－－－－－－

先日リリースした共通部品「ａｈｆｗ」を、本ブログ左側の「ライブラリ・ダウンロード」内のリンク「MT4EA開発共通部品集」からもダウンロードできる様にしました。

●MT4用EA開発用共通部品「ａｈｆｗ」

　－－－－－－－－－－－－－－－－－－

そして、最後にしつこく共通部品「ahfw」の宣伝をして、「FXシステムトレード初心者奮闘記」の「ＭＴ４用ＥＡ開発時代」は、前回掲載した課題の検証に進むのでした。

＃ＭＴ４用ＥＡ共通部品「ahfw」のバグはいつまででも報告お待ちしています。。。