Gekko: Importer don't stop importing at the end of range

Created on 12 Aug 2017  路  19Comments  路  Source: askmike/gekko

Node version: v7.10.0 & v8.2.1
Gekko version: v0.5.2
Exchange: Poloniex
Adapter: any

2017-08-12 21:09:34 (DEBUG):    No end date specified for importing, setting to 2017-08-12 19:09:34
2017-08-12 21:09:34 (INFO):    BTC LSK Requesting data from 2017-08-12 10:00:00, to 2017-08-12 12:00:00
2017-08-12 21:09:35 (DEBUG):    Processing 314 new trades. From 2017-08-12 10:00:44 UTC to 2017-08-12 11:54:08 UTC. (2 hours)
2017-08-12 21:09:36 (INFO):    BTC LSK Requesting data from 2017-08-12 11:50:00, to 2017-08-12 13:50:00
2017-08-12 21:09:37 (DEBUG):    Processing 194 new trades. From 2017-08-12 12:01:27 UTC to 2017-08-12 13:49:36 UTC. (2 hours)
2017-08-12 21:09:38 (INFO):    BTC LSK Requesting data from 2017-08-12 13:40:00, to 2017-08-12 15:40:00
2017-08-12 21:09:38 (DEBUG):    Processing 193 new trades. From 2017-08-12 13:51:33 UTC to 2017-08-12 15:38:37 UTC. (2 hours)
2017-08-12 21:09:39 (INFO):    BTC LSK Requesting data from 2017-08-12 15:30:00, to 2017-08-12 17:30:00
2017-08-12 21:09:40 (DEBUG):    Processing 374 new trades. From 2017-08-12 15:40:04 UTC to 2017-08-12 17:29:38 UTC. (2 hours)
2017-08-12 21:09:41 (INFO):    BTC LSK Requesting data from 2017-08-12 17:20:00, to 2017-08-12 19:20:00
2017-08-12 21:09:42 (DEBUG):    Processing 194 new trades. From 2017-08-12 17:30:25 UTC to 2017-08-12 19:07:59 UTC. (2 hours)
2017-08-12 21:09:43 (INFO):    BTC LSK Requesting data from 2017-08-12 19:10:00, to 2017-08-12 21:10:00
2017-08-12 21:09:43 (DEBUG):    Trade fetch came back empty.
2017-08-12 21:09:44 (INFO):    BTC LSK Requesting data from 2017-08-12 21:00:00, to 2017-08-12 23:00:00
2017-08-12 21:09:45 (DEBUG):    Trade fetch came back empty.
waiting-for-answer
Source
picture SherloxTV

All 19 comments

can you add some more information?

  • what exchange
  • what adapter

Thanks!

askmike picture askmike on 12 Aug 2017
👍1

I added some log.debug() to /importers/exchanges/poloniex.js:

var handleFetch = trades => {
  iterator.from.add(batchSize, 'minutes').subtract(overlapSize, 'minutes');
  iterator.to.add(batchSize, 'minutes').subtract(overlapSize, 'minutes');

  if(!_.size(trades))
    return fetcher.emit('trades', []);

  var last = moment.unix(_.last(trades).date);

  log.debug('LAST > END:', last > end) // <===================

  if(last > end) {
    fetcher.emit('done');

    var endUnix = end.unix();
    trades = _.filter(
      trades,
      t => t.date <= endUnix
    );
  }

  fetcher.emit('trades', trades);
}

Console:

2017-08-13 11:16:35 (DEBUG):    Processing 221 new trades. From 2017-08-12 20:10:57 UTC to 2017-08-12 21:59:46 UTC. (2 hours)
2017-08-13 11:16:36 (INFO): BTC LSK Requesting data from 2017-08-12 21:50:00, to 2017-08-12 23:50:00
2017-08-13 11:16:36 (DEBUG):    LAST > END: false
2017-08-13 11:16:36 (DEBUG):    Processing 560 new trades. From 2017-08-12 22:00:22 UTC to 2017-08-12 23:50:00 UTC. (2 hours)
2017-08-13 11:16:37 (INFO): BTC LSK Requesting data from 2017-08-12 23:40:00, to 2017-08-13 01:40:00
2017-08-13 11:16:38 (DEBUG):    LAST > END: false
2017-08-13 11:16:38 (DEBUG):    Processing 1704 new trades. From 2017-08-12 23:50:48 UTC to 2017-08-13 01:39:45 UTC. (2 hours)
2017-08-13 11:16:39 (INFO): BTC LSK Requesting data from 2017-08-13 01:30:00, to 2017-08-13 03:30:00
2017-08-13 11:16:40 (DEBUG):    LAST > END: false
2017-08-13 11:16:40 (DEBUG):    Processing 614 new trades. From 2017-08-13 01:40:12 UTC to 2017-08-13 03:29:12 UTC. (2 hours)
2017-08-13 11:16:41 (INFO): BTC LSK Requesting data from 2017-08-13 03:20:00, to 2017-08-13 05:20:00
2017-08-13 11:16:41 (DEBUG):    LAST > END: false
2017-08-13 11:16:41 (DEBUG):    Processing 280 new trades. From 2017-08-13 03:31:18 UTC to 2017-08-13 05:17:11 UTC. (2 hours)
2017-08-13 11:16:42 (INFO): BTC LSK Requesting data from 2017-08-13 05:10:00, to 2017-08-13 07:10:00
2017-08-13 11:16:43 (DEBUG):    LAST > END: false
2017-08-13 11:16:43 (DEBUG):    Processing 113 new trades. From 2017-08-13 05:20:31 UTC to 2017-08-13 07:08:24 UTC. (2 hours)
2017-08-13 11:16:44 (INFO): BTC LSK Requesting data from 2017-08-13 07:00:00, to 2017-08-13 09:00:00
2017-08-13 11:16:45 (DEBUG):    LAST > END: false
2017-08-13 11:16:45 (DEBUG):    Processing 561 new trades. From 2017-08-13 07:10:49 UTC to 2017-08-13 08:58:18 UTC. (2 hours)
2017-08-13 11:16:46 (INFO): BTC LSK Requesting data from 2017-08-13 08:50:00, to 2017-08-13 10:50:00
2017-08-13 11:16:47 (DEBUG):    LAST > END: false
2017-08-13 11:16:47 (DEBUG):    Processing 43 new trades. From 2017-08-13 09:02:31 UTC to 2017-08-13 09:15:04 UTC. (13 minutes)
2017-08-13 11:16:48 (INFO): BTC LSK Requesting data from 2017-08-13 10:40:00, to 2017-08-13 12:40:00
2017-08-13 11:16:48 (DEBUG):    Trade fetch came back empty.
2017-08-13 11:16:49 (INFO): BTC LSK Requesting data from 2017-08-13 12:30:00, to 2017-08-13 14:30:00
2017-08-13 11:16:50 (DEBUG):    Trade fetch came back empty.
2017-08-13 11:16:51 (INFO): BTC LSK Requesting data from 2017-08-13 14:20:00, to 2017-08-13 16:20:00
2017-08-13 11:16:52 (DEBUG):    Trade fetch came back empty.
2017-08-13 11:16:53 (INFO): BTC LSK Requesting data from 2017-08-13 16:10:00, to 2017-08-13 18:10:00
2017-08-13 11:16:53 (DEBUG):    Trade fetch came back empty.

We can see that we're out of the handleFetch function, which emit the done event.

SherloxTV picture SherloxTV on 13 Aug 2017

I added a log.debug() to /core/markets/importer.js:

Market.prototype.processTrades = function(trades) {
  this.tradeBatcher.write(trades);

  if(this.done) {
    log.info('Done importing!');
    process.exit(0);
  }

  log.debug('this.done:', this.done)

  if(_.size(trades)) {
    let lastAtTS = _.last(trades).date;
    let lastAt = moment.unix(lastAtTS).utc().format();
    cp.update(lastAt);
  }

  setTimeout(this.get, 1000);
}

Console:

2017-08-13 12:47:16 (INFO): BTC LSK Requesting data from 2017-08-13 08:26:24, to 2017-08-13 10:26:24
2017-08-13 12:47:17 (DEBUG):    LAST > END: false
2017-08-13 12:47:17 (DEBUG):    Processing 492 new trades. From 2017-08-13 08:36:27 UTC to 2017-08-13 10:25:53 UTC. (2 hours)
2017-08-13 12:47:17 (DEBUG):    this.done: false
2017-08-13 12:47:18 (INFO): BTC LSK Requesting data from 2017-08-13 10:16:24, to 2017-08-13 12:16:24
2017-08-13 12:47:19 (DEBUG):    LAST > END: false
2017-08-13 12:47:19 (DEBUG):    Processing 14 new trades. From 2017-08-13 10:26:45 UTC to 2017-08-13 10:46:25 UTC. (20 minutes)
2017-08-13 12:47:19 (DEBUG):    this.done: false
2017-08-13 12:47:20 (INFO): BTC LSK Requesting data from 2017-08-13 12:06:24, to 2017-08-13 14:06:24
2017-08-13 12:47:20 (DEBUG):    Trade fetch came back empty.
2017-08-13 12:47:20 (DEBUG):    this.done: false

So the bug is related to an error in the done event propagation.

SherloxTV picture SherloxTV on 13 Aug 2017

I found the problem:
This is related to the handleFetch function in /importers/exchanges/poloniex.js:

var handleFetch = trades => {
  iterator.from.add(batchSize, 'minutes').subtract(overlapSize, 'minutes');
  iterator.to.add(batchSize, 'minutes').subtract(overlapSize, 'minutes');

  if(!_.size(trades))
    return fetcher.emit('trades', []);

  var last = moment.unix(_.last(trades).date);

  if(last > end) {
    fetcher.emit('done');

    var endUnix = end.unix();
    trades = _.filter(
      trades,
      t => t.date <= endUnix
    );
  }

  fetcher.emit('trades', trades);
}

If the last trade of the last trades batch is valid in terms of datetime, if(last > end) will not trigger. Next batch, but now the batch is empty, so if(!_.size(trades)) is true, we emit a trades event with empty array and we pass to next batch, looping infinite.
As we need if(!_.size(trades)) for potentials empty batchs on low volume markets, I propose the following workaround which works fine:

var handleFetch = trades => {
  iterator.from.add(batchSize, 'minutes').subtract(overlapSize, 'minutes');
  iterator.to.add(batchSize, 'minutes').subtract(overlapSize, 'minutes');

  if(!_.size(trades)) {
    if (iterator.to.subtract(2, 'hour') > end) {
      fetcher.emit('done');
    }
    return fetcher.emit('trades', []);
  }

  var last = moment.unix(_.last(trades).date);

  if(last > end) {
    fetcher.emit('done');

    var endUnix = end.unix();
    trades = _.filter(
      trades,
      t => t.date <= endUnix
    );
  }

  fetcher.emit('trades', trades);
}

@askmike please give me your thoughts on it.

SherloxTV picture SherloxTV on 13 Aug 2017

Can't we just move the if(last > end) above the if(!_.size(trades)) if check?

askmike picture askmike on 13 Aug 2017

This will not solve the problem

SherloxTV picture SherloxTV on 13 Aug 2017

ahhh you are right!

Could you make a PR for this?

The only small thing about it is that iterator.to.subtract(2, 'hour') is not always the same as add(batchSize, 'minutes').subtract(overlapSize, 'minutes');. I think with your proposal you can change the batchSize and have your fix return out early, or not?

askmike picture askmike on 13 Aug 2017

I didn't wanted iterator.to.subtract(2, 'hour'); and iterator.to.add(batchSize, 'minutes').subtract(overlapSize, 'minutes'); to be the same, else I would have used the second on my workaround. I've done this to avoid omitting a batch. What do you mean by change the batchSize ?

SherloxTV picture SherloxTV on 13 Aug 2017

@askmike waiting for your answer to PR :smile:

SherloxTV picture SherloxTV on 14 Aug 2017

I merged your other PR (unrelated from this issue). Will look into this in depth asap!

askmike picture askmike on 14 Aug 2017
👍1

So the main problem I have with:

if(!_.size(trades)) {
  if (iterator.to.subtract(2, 'hour') > end) {
    fetcher.emit('done');
  }
  return fetcher.emit('trades', []);
}

Is that iterator.to.subtract(2, 'hour') mutates: even if the if check ends up being false you still mutate the iterator.to object. In case you want to check (iterator.to MINUS 2 hours) > end, why not simply use iterator.from?

askmike picture askmike on 14 Aug 2017
👍1

Of course ! Sorry sometimes I make non-sense ^^
Will update that and check if ok !

SherloxTV picture SherloxTV on 15 Aug 2017

Awesome, if you update that you can propose a PR (if you want) and we can just test it and merge :)

askmike picture askmike on 16 Aug 2017

Fact is that there is still bugs ... Was trying to import BTC_ETH from Polo and 1 day before the end it said "returned empty trades" and stopped the import, I had to relaunch a hundred times to get the datas...

SherloxTV picture SherloxTV on 16 Aug 2017

Could you post the code you are using?

askmike picture askmike on 16 Aug 2017

I tried with the one discussed just before, and I tried with the original code from fresh git clone too, same behavior ...
Ubuntu 16.04 server 10Mo/s so the context isn't the problem ...

SherloxTV picture SherloxTV on 16 Aug 2017

the one above mutates the iterator.to I am quite sure that breaks something. Did you try based on the iterator.from?

askmike picture askmike on 16 Aug 2017

I tried with the one discussed just before, and I tried with the original code from fresh git clone too, same behavior ...

Can you post logs for this?

askmike picture askmike on 16 Aug 2017

@askmike yes that's what I mean
No sorry no more logs

SherloxTV picture SherloxTV on 16 Aug 2017
Was this page helpful?
0 / 5 - 0 ratings

Related issues

GuyPaddock picture GuyPaddock  路  5Comments
godfrey68 picture godfrey68  路  3Comments
chevinbrown picture chevinbrown  路  3Comments
belemaire picture belemaire  路  5Comments
LeMoussel picture LeMoussel  路  6Comments