Wrong order of timestamps

[TheRealBecks]

I started a backtest and found out that sometimes the timestamps are in the wrong order, so it looks like that the data is wrongly written or read. Here is an example from line 384880:

2019-02-19T09:10:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-02-19T09:10:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.Portfolio:
2019-10-16T17:57:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T18:04:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T18:07:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-10-16T18:07:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-02-19T09:10:00.000000000Z [INF] BACKTESTER-001.EMACross-000:
2019-02-19T17:31:00.000000000Z [INF] BACKTESTER-001.Portfolio:

It jumps from 2019-02-19 to 2019-10-16 and back to 2019-02-19. I attached my whole log.zip file.
(I have some weird coding issue I never saw before. Can't say if it comes from your tool or if it's a Linux bug. Please ignore that in the file for now)

[cjdsellers]

So every time data elements are added to a BacktestEngine the data list is sorted based on ts_init.
backtest/engine.pyx L455.

self._data = sorted(self._data + data, key=lambda x: x.ts_init)

Then, while the backtest is running the logger uses the test clock (rather than real time).
backtest/engine/pyx L906.

self._advance_time(data.ts_init)

However, I believe you're running your backtest in streaming mode? I couldn't see from the logs if you're running with more than one instrument? If so this may relate to #554 and #560.

[TheRealBecks]

It's only the 'AMD' stock data we're talking about since a month - so nothing has been changed on my side :)

[cjdsellers]

I'm closing this just because it's a duplicate of the issue being tracked in #554 and #560

@limx0 is currently debugging it.