search

askmike / gekko

A bitcoin trading bot written in node - https://gekko.wizb.it/
MIT License
10.07k stars 3.94k forks source link

[GDAX] Strategy Execution Delayed or Never Starts #1689

Closed werkkrew closed 6 years ago

werkkrew commented 6 years ago

Note: for support questions, please join our Discord server

    /      \ /        |/  |  /  |/  |  /  | /      \
  /$$$$$$  |$$$$$$$$/ $$ | /$$/ $$ | /$$/ /$$$$$$  |
  $$ | _$$/ $$ |__    $$ |/$$/  $$ |/$$/  $$ |  $$ |
  $$ |/    |$$    |   $$  $$<   $$  $$<   $$ |  $$ |
  $$ |$$$$ |$$$$$/    $$$$$  \  $$$$$  \  $$ |  $$ |
  $$ \__$$ |$$ |_____ $$ |$$  \ $$ |$$  \ $$ \__$$ |
  $$    $$/ $$       |$$ | $$  |$$ | $$  |$$    $$/
   $$$$$$/  $$$$$$$$/ $$/   $$/ $$/   $$/  $$$$$$/

        Gekko v0.5.12
        I'm gonna make you rich, Bud Fox.

2018-01-14 13:59:43 (INFO):     Setting up Gekko in realtime mode
2018-01-14 13:59:43 (INFO):
2018-01-14 13:59:43 (INFO):     Setting up:
2018-01-14 13:59:43 (INFO):              Candle writer
2018-01-14 13:59:43 (INFO):              Store candles in a database
2018-01-14 13:59:43 (INFO):

2018-01-14 13:59:43 (INFO):     Setting up:
2018-01-14 13:59:43 (INFO):              Trading Advisor
2018-01-14 13:59:43 (INFO):              Calculate trading advice
2018-01-14 13:59:43 (INFO):              Using the strategy: private-uber
2018-01-14 13:59:43 (WARN):     TALIB indicators could not be loaded, they will be unavailable.
2018-01-14 13:59:44 (INFO):             The trading method requests 30 minutes of historic data. Checking availablity..
2018-01-14 13:59:44 (INFO):

2018-01-14 13:59:44 (DEBUG):            Available local data:
2018-01-14 13:59:44 (DEBUG):                    from: 30 minutes ago
2018-01-14 13:59:44 (DEBUG):                    to: 3 minutes ago
2018-01-14 13:59:44 (INFO):             Usable local data available, trying to match with exchange data..
2018-01-14 13:59:44 (DEBUG):            Fetching exchange data since 18 minutes ago
2018-01-14 13:59:44 (DEBUG):    Scanning back in the history needed...
2018-01-14 13:59:44 (DEBUG):    2018-01-14T18:41:00Z
2018-01-14 13:59:44 (DEBUG):    Scanning backwards...2018-01-14T18:58:57.053Z
2018-01-14 13:59:44 (DEBUG):    Scanning backwards...2018-01-14T18:50:31.683Z
2018-01-14 13:59:45 (DEBUG):    Scanning backwards...2018-01-14T18:43:25.229Z
2018-01-14 13:59:45 (DEBUG):    Backwards: 2018-01-14T18:37:14.218Z (25831653) to 2018-01-14T18:38:29.88Z (25831752)
2018-01-14 13:59:46 (DEBUG):    Backwards: 2018-01-14T18:38:29.88Z (25831753) to 2018-01-14T18:40:23.799Z (25831852)
2018-01-14 13:59:46 (DEBUG):    Backwards: 2018-01-14T18:40:23.799Z (25831853) to 2018-01-14T18:41:18.352Z (25831952)
2018-01-14 13:59:46 (DEBUG):    Backwards: 2018-01-14T18:41:18.352Z (25831953) to 2018-01-14T18:43:25.229Z (25832052)
2018-01-14 13:59:47 (DEBUG):    Backwards: 2018-01-14T18:43:25.229Z (25832053) to 2018-01-14T18:45:03.877Z (25832152)
2018-01-14 13:59:47 (DEBUG):    Backwards: 2018-01-14T18:45:03.877Z (25832153) to 2018-01-14T18:48:17.782Z (25832252)
2018-01-14 13:59:48 (DEBUG):    Backwards: 2018-01-14T18:48:17.782Z (25832253) to 2018-01-14T18:50:31.683Z (25832352)
2018-01-14 13:59:48 (DEBUG):    Backwards: 2018-01-14T18:50:31.683Z (25832353) to 2018-01-14T18:54:51.452Z (25832452)
2018-01-14 13:59:49 (DEBUG):    Backwards: 2018-01-14T18:54:51.548Z (25832453) to 2018-01-14T18:58:57.053Z (25832552)
2018-01-14 13:59:49 (DEBUG):    Backwards: 2018-01-14T18:58:57.053Z (25832553) to 2018-01-14T18:59:17.028Z (25832652)
2018-01-14 13:59:49 (DEBUG):    Backwards: 2018-01-14T18:59:04.244Z (25832585) to 2018-01-14T18:59:26.198Z (25832684)
2018-01-14 13:59:50 (DEBUG):    Backwards: 2018-01-14T18:59:04.244Z (25832585) to 2018-01-14T18:59:26.198Z (25832684)
2018-01-14 13:59:50 (DEBUG):    Scan finished: data found:1200
2018-01-14 13:59:50 (DEBUG):            Available exchange data:
2018-01-14 13:59:50 (DEBUG):                    from: 22 minutes ago
2018-01-14 13:59:50 (DEBUG):                    to: 0 minutes ago
2018-01-14 13:59:50 (DEBUG):            Stitching datasets
2018-01-14 13:59:50 (INFO):             Full history locally available. Seeding the trading method with all required historical candles.
2018-01-14 13:59:50 (DEBUG):            Seeding with:
2018-01-14 13:59:50 (DEBUG):                    from: 30 minutes ago
2018-01-14 13:59:50 (DEBUG):                    to: 23 minutes ago
2018-01-14 13:59:50 (INFO):     Setting up:
2018-01-14 13:59:50 (INFO):              Advice logger
2018-01-14 13:59:50 (INFO):
2018-01-14 13:59:50 (INFO):     Setting up:
2018-01-14 13:59:50 (INFO):              Trader
2018-01-14 13:59:50 (INFO):              Follows the advice and create real orders.
2018-01-14 13:59:50 (DEBUG):    getting ticker, balance & fee from GDAX
2018-01-14 13:59:50 (INFO):

2018-01-14 13:59:50 (INFO):     trading at GDAX ACTIVE
2018-01-14 13:59:50 (INFO):     GDAX trading fee will be: 0%
2018-01-14 13:59:50 (INFO):     GDAX portfolio:
2018-01-14 13:59:50 (INFO):              USD: 107.764582949200
2018-01-14 13:59:50 (INFO):              ETH: 0.069314510000
2018-01-14 13:59:50 (INFO):     Setting up:
2018-01-14 13:59:50 (INFO):              Performance Analyzer
2018-01-14 13:59:50 (INFO):              Analyzes performances of trades
2018-01-14 13:59:50 (INFO):

2018-01-14 13:59:50 (INFO):     Starting to watch the market: GDAX ETH/USD
2018-01-14 13:59:50 (DEBUG):    scheduling ticks
2018-01-14 13:59:50 (DEBUG):    Requested ETH/USD trade data from GDAX ...
2018-01-14 13:59:50 (DEBUG):    Scanning back in the history needed...
2018-01-14 13:59:50 (DEBUG):    2018-01-14T18:41:00Z
2018-01-14 13:59:50 (DEBUG):    Scanning backwards...2018-01-14T18:59:04.244Z
2018-01-14 13:59:51 (DEBUG):    Scanning backwards...2018-01-14T18:52:00.341Z
2018-01-14 13:59:51 (DEBUG):    Scanning backwards...2018-01-14T18:43:56.558Z
2018-01-14 13:59:51 (DEBUG):    Backwards: 2018-01-14T18:37:14.218Z (25831685) to 2018-01-14T18:39:18.798Z (25831784)
2018-01-14 13:59:52 (DEBUG):    Backwards: 2018-01-14T18:39:19.024Z (25831785) to 2018-01-14T18:40:50.713Z (25831884)
2018-01-14 13:59:52 (DEBUG):    Backwards: 2018-01-14T18:40:51.642Z (25831885) to 2018-01-14T18:41:52.945Z (25831984)
2018-01-14 13:59:53 (DEBUG):    Backwards: 2018-01-14T18:41:58.929Z (25831985) to 2018-01-14T18:43:56.558Z (25832084)
2018-01-14 13:59:53 (DEBUG):    Backwards: 2018-01-14T18:43:56.558Z (25832085) to 2018-01-14T18:45:29.074Z (25832184)
2018-01-14 13:59:54 (DEBUG):    Backwards: 2018-01-14T18:45:29.074Z (25832185) to 2018-01-14T18:49:06.105Z (25832284)
2018-01-14 13:59:54 (DEBUG):    Backwards: 2018-01-14T18:49:06.105Z (25832285) to 2018-01-14T18:51:58.062Z (25832384)
2018-01-14 13:59:55 (DEBUG):    Backwards: 2018-01-14T18:52:00.341Z (25832385) to 2018-01-14T18:56:20.079Z (25832484)
2018-01-14 13:59:55 (DEBUG):    Backwards: 2018-01-14T18:56:25.263Z (25832485) to 2018-01-14T18:59:04.244Z (25832584)
2018-01-14 13:59:55 (DEBUG):    Backwards: 2018-01-14T18:59:04.244Z (25832585) to 2018-01-14T18:59:26.198Z (25832684)
2018-01-14 13:59:56 (DEBUG):    Backwards: 2018-01-14T18:59:04.244Z (25832602) to 2018-01-14T18:59:31.805Z (25832701)
2018-01-14 13:59:56 (DEBUG):    Backwards: 2018-01-14T18:59:04.244Z (25832603) to 2018-01-14T18:59:33.609Z (25832702)
2018-01-14 13:59:57 (DEBUG):    Backwards: 2018-01-14T18:59:04.244Z (25832603) to 2018-01-14T18:59:33.609Z (25832702)
2018-01-14 13:59:57 (DEBUG):    Scan finished: data found:1300
2018-01-14 13:59:57 (DEBUG):    Processing 1300 new trades. From 2018-01-14 18:37:14 UTC to 2018-01-14 18:59:33 UTC. (22 minutes)
2018-01-14 14:00:10 (DEBUG):    Requested ETH/USD trade data from GDAX ...
2018-01-14 14:00:10 (DEBUG):    Processing 31 new trades. From 2018-01-14 18:59:34 UTC to 2018-01-14 18:59:47 UTC. (a few seconds)
2018-01-14 14:00:30 (DEBUG):    Requested ETH/USD trade data from GDAX ...
2018-01-14 14:00:30 (DEBUG):    Processing 53 new trades. From 2018-01-14 18:59:49 UTC to 2018-01-14 19:00:05 UTC. (a few seconds)
2018-01-14 14:00:50 (DEBUG):    Requested ETH/USD trade data from GDAX ...
2018-01-14 14:00:50 (DEBUG):    Processing 10 new trades. From 2018-01-14 19:00:08 UTC to 2018-01-14 19:00:27 UTC. (a few seconds)
2018-01-14 14:01:10 (DEBUG):    Requested ETH/USD trade data from GDAX ...
2018-01-14 14:01:10 (DEBUG):    Processing 17 new trades. From 2018-01-14 19:00:30 UTC to 2018-01-14 19:00:46 UTC. (a few seconds)
askmike commented 6 years ago

What makes you think the strategy didn't start in this case?

werkkrew commented 6 years ago

@askmike I have a lot of logging. I should have been more clear in that the "check" method of a strategy is delayed or never starts.

It seems like once the bot runs for the "requiredHistory" amount of time, in real time, it will work. Sometimes the history does work, sometimes it does not.

werkkrew commented 6 years ago

I believe I have narrowed this down a bit and I don't think it is necessarily unique to GDAX.

Once a strategy gets sufficiently complicated it seems like if certain things can't happen fast enough between the "tickrate" timeframe, Gekko starts to act strange.

In this case of this snippet the tickrate was set to 5. If I increased it to 20, it behaved more like I expected.

Once my strategy got even more complicated, I had to increase the tickrate to 30, otherwise even if the strategy did start to execute the "check" method, the results of about 10% of my tulip indicators would come back with NaN as a result.

It seems that adjusting the tickrate to exceed the time it takes for the "update" method to fully complete is a workaround.

werkkrew commented 6 years ago

So I did a bit more testing and this time I used Binance and I am still able to re-create the issue. I am honestly not sure exactly what one must do to re-create the issue but it happens to be pretty regularly.

I usually do a fresh import just before I try to run Gekko to ensure it has as much locally available history as possible.

In my config I have requiredHistory set to 60 and candlesize set to either 1 or 5. tickrate is set at the default of 20

I added a line to baseTradingMethod.js at line 224 just below the definition of isAllowedToCheck with the following: log.debug('REQUIRED HISTORY:', this.requiredHistory, 'AGE:', this.age, 'IS ALLOWED TO CHECK:', isAllowedToCheck);

The output is attached at the bottom of this comment. My suspicion is that relatively complex strategies have an update method that exceeds some amount of time to complete and it breaks something, but I am not 100% sure.

______   ________  __    __  __    __   ______

/ \ / |/ | / |/ | / | / \ /$$$$$$ |$$$$$$$$/ $$ | /$$/ $$ | /$$/ /$$$$$$ | $$ | $$/ $$ | $$ |/$$/ $$ |/$$/ $$ | $$ | $$ |/ |$$ | $$ $$< $$ $$< $$ | $$ | $$ |$$$$ |$$$$$/ $$$$$ \ $$$$$ \ $$ | $$ | $$ \$$ |$$ |____ $$ |$$ \ $$ |$$ \ $$ __$$ | $$ $$/ $$ |$$ | $$ |$$ | $$ |$$ $$/ $$$$$$/ $$$$$$$$/ $$/ $$/ $$/ $$/ $$$$$$/

    Gekko v0.5.12
    I'm gonna make you rich, Bud Fox.

2018-01-22 12:18:17 (INFO): Setting up Gekko in realtime mode 2018-01-22 12:18:17 (INFO): 2018-01-22 12:18:17 (INFO): Setting up: 2018-01-22 12:18:17 (INFO): Candle writer 2018-01-22 12:18:17 (INFO): Store candles in a database 2018-01-22 12:18:17 (INFO):

2018-01-22 12:18:17 (INFO): Setting up: 2018-01-22 12:18:17 (INFO): Trading Advisor 2018-01-22 12:18:17 (INFO): Calculate trading advice 2018-01-22 12:18:17 (INFO): Using the strategy: private-uber 2018-01-22 12:18:17 (WARN): TALIB indicators could not be loaded, they will be unavailable. 2018-01-22 12:18:18 (INFO): The trading method requests 300 minutes of historic data. Checking availablity.. 2018-01-22 12:18:18 (INFO):

2018-01-22 12:18:18 (DEBUG): Available local data: 2018-01-22 12:18:18 (DEBUG): from: 138 minutes ago 2018-01-22 12:18:18 (DEBUG): to: 2 minutes ago 2018-01-22 12:18:18 (INFO): Usable local data available, trying to match with exchange data.. 2018-01-22 12:18:18 (DEBUG): Fetching exchange data since 17 minutes ago 2018-01-22 12:18:19 (DEBUG): Available exchange data: 2018-01-22 12:18:19 (DEBUG): from: 17 minutes ago 2018-01-22 12:18:19 (DEBUG): to: 0 minutes ago 2018-01-22 12:18:19 (DEBUG): Stitching datasets 2018-01-22 12:18:19 (INFO): Partial history locally available, but 162 minutes are missing. 2018-01-22 12:18:19 (INFO): Seeding the trading method with partial historical data (Gekko needs more time before it can give advice). 2018-01-22 12:18:19 (DEBUG): Seeding with: 2018-01-22 12:18:19 (DEBUG): from: 138 minutes ago 2018-01-22 12:18:19 (DEBUG): to: 18 minutes ago 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 1 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 2 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 3 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 4 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 5 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 6 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 7 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 8 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 9 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 10 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 11 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 12 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 13 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 14 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 15 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 16 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 17 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 18 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 19 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 20 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 21 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 22 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 23 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (DEBUG): REQUIRED HISTORY: 60 AGE: 24 IS ALLOWED TO CHECK: false 2018-01-22 12:18:19 (INFO): Setting up: 2018-01-22 12:18:19 (INFO): Advice logger 2018-01-22 12:18:19 (INFO): 2018-01-22 12:18:19 (INFO): Setting up: 2018-01-22 12:18:19 (INFO): Trader 2018-01-22 12:18:19 (INFO): Follows the advice and create real orders. 2018-01-22 12:18:19 (DEBUG): Trade timer is active. Trades will expire after 60 seconds. 2018-01-22 12:18:19 (DEBUG): The exchange does not provide a websocket feed (or Gekko doesn't support listening to it) 2018-01-22 12:18:19 (DEBUG): Getting ticker, balance & fee from binance 2018-01-22 12:18:19 (INFO): 2018-01-22 12:18:21 (DEBUG): [binance.js] entering "setBalance" callback after api call, err: null, data: [object Object] 2018-01-22 12:18:21 (INFO): Trading at binance ACTIVE 2018-01-22 12:18:21 (INFO): binance trading fee will be: 0.1% 2018-01-22 12:18:21 (INFO): binance portfolio: 2018-01-22 12:18:21 (INFO): ETH: 0.000323320000 2018-01-22 12:18:21 (INFO): ADA: 0.000000000000 2018-01-22 12:18:21 (INFO): Setting up: 2018-01-22 12:18:21 (INFO): Performance Analyzer 2018-01-22 12:18:21 (INFO): Analyzes performances of trades 2018-01-22 12:18:21 (INFO):

2018-01-22 12:18:21 (INFO): Starting to watch the market: Binance ADA/ETH 2018-01-22 12:18:21 (DEBUG): Scheduling ticks... 2018-01-22 12:18:21 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:18:22 (DEBUG): Processing 351 new trades. From 2018-01-22 17:01:01 UTC to 2018-01-22 17:18:15 UTC. (17 minutes) 2018-01-22 12:18:22 (DEBUG): REQUIRED HISTORY: 60 AGE: 25 IS ALLOWED TO CHECK: false 2018-01-22 12:18:22 (DEBUG): REQUIRED HISTORY: 60 AGE: 26 IS ALLOWED TO CHECK: false 2018-01-22 12:18:22 (DEBUG): REQUIRED HISTORY: 60 AGE: 27 IS ALLOWED TO CHECK: false 2018-01-22 12:18:41 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:18:42 (DEBUG): Processing 11 new trades. From 2018-01-22 17:18:23 UTC to 2018-01-22 17:18:41 UTC. (a few seconds) 2018-01-22 12:19:01 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:19:02 (DEBUG): Processing 3 new trades. From 2018-01-22 17:18:49 UTC to 2018-01-22 17:18:56 UTC. (a few seconds) 2018-01-22 12:19:21 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:19:22 (DEBUG): Processing 20 new trades. From 2018-01-22 17:19:03 UTC to 2018-01-22 17:19:21 UTC. (a few seconds) 2018-01-22 12:19:41 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:19:42 (DEBUG): Processing 7 new trades. From 2018-01-22 17:19:27 UTC to 2018-01-22 17:19:36 UTC. (a few seconds) 2018-01-22 12:20:01 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:20:03 (DEBUG): Processing 6 new trades. From 2018-01-22 17:19:43 UTC to 2018-01-22 17:19:58 UTC. (a few seconds) 2018-01-22 12:20:21 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:20:22 (DEBUG): Processing 5 new trades. From 2018-01-22 17:20:09 UTC to 2018-01-22 17:20:22 UTC. (a few seconds) 2018-01-22 12:20:22 (DEBUG): REQUIRED HISTORY: 60 AGE: 28 IS ALLOWED TO CHECK: false 2018-01-22 12:20:41 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:20:43 (DEBUG): Processing 7 new trades. From 2018-01-22 17:20:22 UTC to 2018-01-22 17:20:42 UTC. (a few seconds) 2018-01-22 12:21:01 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:21:02 (DEBUG): Processing 4 new trades. From 2018-01-22 17:20:45 UTC to 2018-01-22 17:21:01 UTC. (a few seconds) 2018-01-22 12:21:21 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:21:22 (DEBUG): Processing 2 new trades. From 2018-01-22 17:21:10 UTC to 2018-01-22 17:21:16 UTC. (a few seconds) 2018-01-22 12:21:41 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:21:43 (DEBUG): Processing 12 new trades. From 2018-01-22 17:21:26 UTC to 2018-01-22 17:21:37 UTC. (a few seconds) 2018-01-22 12:22:01 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:22:02 (DEBUG): Processing 9 new trades. From 2018-01-22 17:21:42 UTC to 2018-01-22 17:21:58 UTC. (a few seconds) 2018-01-22 12:22:21 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:22:22 (DEBUG): Processing 11 new trades. From 2018-01-22 17:22:04 UTC to 2018-01-22 17:22:22 UTC. (a few seconds) 2018-01-22 12:22:41 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:22:43 (DEBUG): Processing 15 new trades. From 2018-01-22 17:22:22 UTC to 2018-01-22 17:22:41 UTC. (a few seconds) 2018-01-22 12:23:01 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:23:02 (DEBUG): Processing 5 new trades. From 2018-01-22 17:22:43 UTC to 2018-01-22 17:22:54 UTC. (a few seconds) 2018-01-22 12:23:21 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:23:22 (DEBUG): Processing 3 new trades. From 2018-01-22 17:23:08 UTC to 2018-01-22 17:23:19 UTC. (a few seconds) 2018-01-22 12:23:41 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:23:43 (DEBUG): Processing 6 new trades. From 2018-01-22 17:23:24 UTC to 2018-01-22 17:23:38 UTC. (a few seconds) 2018-01-22 12:24:01 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:24:03 (DEBUG): Processing 3 new trades. From 2018-01-22 17:23:43 UTC to 2018-01-22 17:23:52 UTC. (a few seconds) 2018-01-22 12:24:21 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:24:22 (DEBUG): Processing 12 new trades. From 2018-01-22 17:24:05 UTC to 2018-01-22 17:24:18 UTC. (a few seconds) 2018-01-22 12:24:41 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:24:42 (DEBUG): Processing 5 new trades. From 2018-01-22 17:24:40 UTC to 2018-01-22 17:24:41 UTC. (a few seconds) 2018-01-22 12:25:01 (DEBUG): Requested ADA/ETH trade data from Binance ... 2018-01-22 12:25:03 (DEBUG): Processing 10 new trades. From 2018-01-22 17:24:46 UTC to 2018-01-22 17:25:02 UTC. (a few seconds) 2018-01-22 12:25:03 (DEBUG): REQUIRED HISTORY: 60 AGE: 29 IS ALLOWED TO CHECK: false 2018-01-22 12:25:21 (DEBUG): Requested ADA/ETH trade data from Binance ...

talentoscope commented 6 years ago

I can confirm this issue with Kraken. Not too complicated a strategy either. Seems to me to be to do with the required history. If I use less than an hour, it seems fine, any longer than 1 hr 20 or so and it'll just hang and do the same as above. It shows that it grabs local data and stitches, but the strategy never seems to start when logging should show output from log.info in the strategy of gekko showing tulip EMAs and whatnot.

Looks to me from that output that the importer doesn't get a chance to finish grabbing history before the tradeadvisor starts, and then it doesn't bother after that.

ansonphong commented 6 years ago

I was experiencing a similar issue because my strategy.requiredHistory value was greater than the trading advisor history size. This was easily fixed by setting this in my strategy.init method:

this.requiredHistory = this.tradingAdvisor.historySize;

So the second similar issue I was facing was that, even though it was priming the strategy.update method with backdata, it wasn't starting to trade on the first live candle, it was delaying a full candle before starting trades on the live market. This is because it defines:

isPremature = candle.start < startTime;

If it's premature, it doesn't start trading, though the first whole live candle was being called premature, although I wanted to start trading right away. The way I use the bot I need it to instantly start trading, so I modified baseTradingMethod.js to subtract the candle size from the start time to determine if it's premature.

// in live mode we might receive more candles
  // than minimally needed. In that case check
  // whether candle start time is > startTime
  var isPremature;

  // Subtract number of minutes in current candle for instant start
  let startTimeMinusCandleSize = startTime.clone();
  startTimeMinusCandleSize.subtract(this.tradingAdvisor.candleSize, "minutes"); 

  if(mode === 'realtime'){
    isPremature = candle.start < startTimeMinusCandleSize;
  }
  else{
    isPremature = false;
  }

This causes it to start trading on the first live candle. Perhaps this is related to your issue?

talentoscope commented 6 years ago

No, that's not the issue for either of us. We've discussed it on Discord and it seems to be a race condition caused by the use of tulip indicators.

dreammaker commented 6 years ago

I'm running into this problem also. I'm not using TALIB or Tulip, so I think the problem may be something else. I don't have any recent local data, so it's only exchange data fetching. I'm setting candleSize to 1 and historySize to 10 as a test.

I'm reading through dataStitcher.js. I see that in seedLocalData() it uses candles from local data and passes them to the batcher. However, where is the exchange data ever used? In checkExchangeTrades(), it seems like the resulting trades from the exchange are discarded. Only the from and to dates are passed to the callback. What am I missing here? Does getTrades() have some magic in it that propagates the trades?

Here is my CLI output. Strategy's check() isn't getting called for a long time.

2018-04-12 17:13:18 (INFO): Setting up Gekko in realtime mode
2018-04-12 17:13:18 (INFO):
2018-04-12 17:13:18 (INFO): Setting up:
2018-04-12 17:13:18 (INFO):      Trading Advisor
2018-04-12 17:13:18 (INFO):      Calculate trading advice
2018-04-12 17:13:18 (INFO):      Using the strategy: MACD
2018-04-12 17:13:18 (WARN): TALIB indicators could not be loaded, they will be unavailable.
2018-04-12 17:13:18 (WARN): TULIP indicators could not be loaded, they will be unavailable.
2018-04-12 17:13:19 (INFO):     The trading method requests 10 minutes of historic data. Checking availablity..
2018-04-12 17:13:19 (INFO):

2018-04-12 17:13:19 (INFO):     No usable local data available, trying to get as much as possible from the exchange..
2018-04-12 17:13:19 (DEBUG):        Fetching exchange data since 10 minutes ago
2018-04-12 17:13:19 (DEBUG):    Scanning back in the history needed...
2018-04-12 17:13:19 (DEBUG):    2018-04-12T21:03:00Z
2018-04-12 17:13:19 (DEBUG):    Scanning backwards...2018-04-12T21:09:25.402Z
2018-04-12 17:13:19 (DEBUG):    Scanning backwards...2018-04-12T21:03:26.859Z
2018-04-12 17:13:20 (DEBUG):    Backwards: 2018-04-12T20:58:10.082Z (41498351) to 2018-04-12T20:59:25.664Z (41498450)
2018-04-12 17:13:20 (DEBUG):    Backwards: 2018-04-12T20:59:25.664Z (41498451) to 2018-04-12T20:59:46.191Z (41498550)
2018-04-12 17:13:21 (DEBUG):    Backwards: 2018-04-12T20:59:46.191Z (41498551) to 2018-04-12T21:03:26.859Z (41498650)
2018-04-12 17:13:21 (DEBUG):    Backwards: 2018-04-12T21:03:26.859Z (41498651) to 2018-04-12T21:06:48.829Z (41498750)
2018-04-12 17:13:22 (DEBUG):    Backwards: 2018-04-12T21:06:49.589Z (41498751) to 2018-04-12T21:09:25.402Z (41498850)
2018-04-12 17:13:22 (DEBUG):    Backwards: 2018-04-12T21:09:25.402Z (41498851) to 2018-04-12T21:13:17.061Z (41498950)
2018-04-12 17:13:23 (DEBUG):    Backwards: 2018-04-12T21:09:25.402Z (41498851) to 2018-04-12T21:13:17.061Z (41498950)
2018-04-12 17:13:23 (DEBUG):    Scan finished: data found:700
2018-04-12 17:13:23 (DEBUG):        Available exchange data:
2018-04-12 17:13:23 (DEBUG):            from: 15 minutes ago
2018-04-12 17:13:23 (DEBUG):            to: 0 minutes ago
2018-04-12 17:13:23 (DEBUG):        Unable to stitch datasets.
2018-04-12 17:13:23 (INFO):     Not seeding locally available data to the trading method.
2018-04-12 17:13:23 (INFO):     However the exchange returned enough data anyway!
2018-04-12 17:13:23 (INFO): Starting to watch the market: GDAX BTC/USD
2018-04-12 17:13:23 (DEBUG):    scheduling ticks
2018-04-12 17:13:23 (DEBUG):    Requested BTC/USD trade data from GDAX ...
2018-04-12 17:13:23 (DEBUG):    Processing 100 new trades. From 2018-04-12 21:09:25 UTC to 2018-04-12 21:13:17 UTC. (4 minutes)
dreammaker commented 6 years ago

2112 fixes my problem. However, I'm not sure it closes this issue.

stale[bot] commented 6 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions. If you feel this is very a important issue please reach out the maintainer of this project directly via e-mail: gekko at mvr dot me.