Buggy iClose ?

 

Today Friday 20 December 2013 (GMT+1), I have identified two situations where iClose at first returned incorrect values.

What follows are snippets from my log-files (time-stamped GMT+1).


2013-12-20 00:00:03.7687|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, <-- ###MQL###|iClose|USDCHF|1440|1
2013-12-20 00:00:03.7687|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, --> 0:no error|0.89730000
WRONG: USDCHF closed on 19-Dec-2013 at 0.89787 according to my chart in the terminal

2013-12-20 10:59:56.5527|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|15|, <-- ###MQL###|iClose|USDCAD|1440|1
2013-12-20 10:59:56.5527|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|15|, --> 0:no error|1.06846000
WRONG: USDCAD closed on 19-Dec-2013 at 1.06625 according to my chart in the terminal, which the following log-snippet supports
2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, <-- ###MQL###|iClose|USDCAD|1440|1
2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, --> 0:no error|1.06625000
Correct....


I have had my expert running for about a week now, and these two instances are the only two where I've seen incorrect behavior.


Has anyone else experienced similar issues ?

 
numbnaive:

Today Friday 20 December 2013 (GMT+1), I have identified two situations where iClose at first returned incorrect values.


How do you ensure you have uptodate data for USDCAD and USDCHF ?
 
numbnaive: 2013-12-20 00:00:03.7687|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, <-- ###MQL###|iClose|USDCHF|1440|1
You appear to be looking at the D1 bar 1 value, but if your chart isn't the D1, the D1 may not have been updated yet. Find the correct bar index ALWAYS.
#define HR2400 86400       // 24 * 3600
int      TimeOfDay(datetime when){  return( when % HR2400          );         }
datetime DateOfDay(datetime when){  return( when - TimeOfDay(when) );         }
datetime Today(    datetime when=0){      if(when == 0)  when = TimeCurrent();
                                          return(DateOfDay( TimeCurrent() )); }
:
datetime yesterday  = Today() - 1;
int      iD1        = iBarShift(NULL, PERIOD_D1, yesterday);
double   closeEOD   = iClose(NULL, PERIOD_D1, iD1);
 
RaptorUK:
How do you ensure you have uptodate data for USDCAD and USDCHF ?


I wait for GetLastError to return 0. The snippets below support that I discard results if the error code is 4066 (requested history update is in update state)


2013-12-20 14:06:14.6517|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|6|, <-- ###MQL###|iClose|USDCAD|1440|1
2013-12-20 14:06:14.6567|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|6|, --> 4066:requested history data in update state|1.06625000
2013-12-20 14:06:14.6567|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Error|11|Handler execution failed with error 'MQL returned error: '4066:requested history data in update state' for method iClose(USDCAD, 1440, 1). Failure Context: [HandlerName=NaiveUsdCad, Discriminator=17523NaiveUsdCad].QuoteReceived(1.06773000;1.06796000;1387551978)'. Failure Context: [HandlerName=NaiveUsdCad, Discriminator=17523NaiveUsdCad].QuoteReceived(1.06772000;1.06794000;1387551978),
2013-12-20 14:06:14.6567|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|6|, <-- ###ERR###|Handler execution failed with error 'MQL returned error: '4066:requested history data in update state' for method iClose(USDCAD, 1440, 1). Failure Context: [HandlerName=NaiveUsdCad, Discriminator=17523NaiveUsdCad].QuoteReceived(1.06773000;1.06796000;1387551978)'. Failure Context: [HandlerName=NaiveUsdCad, Discriminator=17523NaiveUsdCad].QuoteReceived(1.06772000;1.06794000;1387551978)
2013-12-20 14:06:14.6567|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|6|, Method execution time: 12 ms.
2013-12-20 14:06:14.6567|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|6|, Connection closed
2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, Connection opened
2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, --> 17523|NaiveUsdCad|QuoteReceived|1.06771000;1.06794000;1387551979|
2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, <-- ###MQL###|iClose|USDCAD|1440|1

2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, --> 0:no error|1.06625000

 
WHRoeder:
You appear to be looking at the D1 bar 1 value, but if your chart isn't the D1, the D1 may not have been updated yet. Find the correct bar index ALWAYS.


You are right, I am looking at daily closes ie. D1 and 1 bar back.

I understand what you are trying to do with the code -- ensuring I get the right bar.

The problem is not missing a bar, as the return values iClose() return do not match any previous close values.

The problem is that iClose has reported incorrect values, at first (even after ensuring all historic data is loaded), then it reports correct values.

Computational issues at the broker, or a bug deep down Metatrade ?

 

I wonder if MT4 rewrites the last bar each time, so if ticks were missed it is corrected on the chart as per HLOC. You would have to record all recieved ticks to verify if that is the case, then disconnect the internet a couple of minutes before the end of a bar, then reconnect after begin time of the next bar. If previous bar is corrected on the chart your log will show a difference and you will know your errors are caused by some missed ticks at the end of a bar.

 
numbnaive:

I wait for GetLastError to return 0. The snippets below support that I discard results if the error code is 4066 (requested history update is in update state)

And how long do you wait for the data to arrive before trying it again ? after you get the error 4066 it goes away . . . then some time later the data will have arrived, just because you don't get a new error 4066 doesn't mean the data has now arrived and is updated.
 
RaptorUK:
And how long do you wait for the data to arrive before trying it again ? after you get the error 4066 it goes away . . . then some time later the data will have arrived, just because you don't get a new error 4066 doesn't mean the data has now arrived and is updated.


I generally try again at next tick -- in the snippet above, I try after approximately 150ms == 0.15second.


I am seriously disturbed if what you write is correct: "just because you don't get a new error 4066 doesn't mean the data has now arrived and is updated"


How is one then to know when data has arrived and is available ?

 
SDC:

I wonder if MT4 rewrites the last bar each time, so if ticks were missed it is corrected on the chart as per HLOC. You would have to record all recieved ticks to verify if that is the case, then disconnect the internet a couple of minutes before the end of a bar, then reconnect after begin time of the next bar. If previous bar is corrected on the chart your log will show a difference and you will know your errors are caused by some missed ticks at the end of a bar.

The last USDCAD tick on 19-Dec-2013
2013-12-19 22:59:49.3002|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, --> 7176|NaiveUsdCad|QuoteReceived|1.06625000;1.06653000;1387497593|
...
Now follows the incorrect closing rate (approximately 12 hours later)
2013-12-20 10:59:56.5527|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|15|, <-- ###MQL###|iClose|USDCAD|1440|1
2013-12-20 10:59:56.5527|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|15|, --> 0:no error|1.06846000
...
Now follows the correct closing rate (approximately 15 hours later)
2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, <-- ###MQL###|iClose|USDCAD|1440|1
2013-12-20 14:06:14.8027|TradePlatform.MT4.Core.Nlog.NlogEntryLogger|Debug|4|, --> 0:no error|1.06625000


What closing rate for USDCAD on 19-Dec-2013 do others have ?

 
numbnaive:

I generally try again at next tick -- in the snippet above, I try after approximately 150ms == 0.15second.


I am seriously disturbed if what you write is correct: "just because you don't get a new error 4066 doesn't mean the data has now arrived and is updated"


How is one then to know when data has arrived and is available ?

Off the top of my head . . . save it's open time, if you get an error 4066 re-read until you get a different open time . . . or just wait a reasonable number of seconds, I have seen 15 seconds suggested.
 

Thank you all for your input, in particular RaptorUK.


Since my EA is used for trading, I have devised these steps in order to mitigate the risk of data-corruption:

1) try to acquire EOD closing rates well in advance before they are actually needed. My algo allows for this.

2) have a human verify the values each day

3) compute HLOC-bars myself from the ticks received and compare with the acquired and humanly-accepted values

4) in case of continued discrepancies, invite the broker for coffee :-)


It just dawned on me that I am using build 509 (24 Jun 2013) -- could this really be the issue ??