throw 'weird error'

[djmuk]

I know this is also mixed in with the stiff about the database rewrite but thought it should have a ticket!

Got the following at midnight again:

2013-12-31 23:58:02 (INFO):     Processed trades, sleeping for a minute ...
2013-12-31 23:59:03 (INFO):     @ P:0.04232363 (L:0.04197005, S:0.04208345, M:0.270, s:0.210, D:0.060)
2013-12-31 23:59:03 (INFO):     Processed trades, sleeping for a minute ...
2014-01-01 00:00:04 (INFO):     @ P:0.04232351 (L:0.04200193, S:0.04212658, M:0.296, s:0.227, D:0.069)
2014-01-01 00:00:04 (INFO):     Processed trades, sleeping for a minute ...

D:\Users\David\Documents\GitHub\gekko\core\databaseManager.js:396
        throw 'Weird error';
        ^
Weird error

D:\Users\David\Downloads\bitcpind etc\Gekko - github>pause
Press any key to continue . . .

(ignore the extra logging etc - that's my WIP)

I turned debug logging back on and restarted and it worked OK... even though there were trades over the 2 days in the batch:

2014-01-01 00:08:05 (DEBUG):    Fetched 1001 new trades, from 2013-12-31 23:53:40 (UTC) to 2014-01-01 00:08:11 (UTC)
2014-01-01 00:08:05 (WARN):     Found a corrupted database ( 2014-01-01 ), going to clean it up
2014-01-01 00:08:05 (DEBUG):    This should not happen, please post details here: https://github.com/askmike/gekko/issues/90
2014-01-01 00:08:05 (INFO):     No history found, starting to build one now
2014-01-01 00:08:05 (INFO):     Expected to start giving advice in 15 minutes (2014-01-01 00:23:05 UTC)
2014-01-01 00:08:05 (DEBUG):    minimum trade treshold: 2013-12-31 00:00:00 UTC
2014-01-01 00:08:05 (DEBUG):    processing 1001 trade(s)
2014-01-01 00:08:05 (DEBUG):    This batch includes trades for a new day.
2014-01-01 00:08:05 (DEBUG):    Creating a new daily database for day 2014-01-01
2014-01-01 00:08:05 (DEBUG):    inserting candle 1433 (2013-12-31 23:53:00 UTC) volume: 11.954575080000003
2014-01-01 00:08:05 (DEBUG):    inserting candle 0 (2014-01-01 00:00:00 UTC) volume: 16.124215590000002
2014-01-01 00:08:05 (DEBUG):    inserting candle 1434 (2013-12-31 23:54:00 UTC) volume: 206.07600889999966
2014-01-01 00:08:05 (DEBUG):    inserting candle 1 (2014-01-01 00:01:00 UTC) volume: 94.74862686999998
2014-01-01 00:08:05 (DEBUG):    inserting candle 1435 (2013-12-31 23:55:00 UTC) volume: 4.30453102
2014-01-01 00:08:05 (DEBUG):    inserting candle 2 (2014-01-01 00:02:00 UTC) volume: 9.29201837
2014-01-01 00:08:05 (DEBUG):    inserting candle 1436 (2013-12-31 23:56:00 UTC) volume: 7.483524389999999
2014-01-01 00:08:05 (DEBUG):    inserting candle 3 (2014-01-01 00:03:00 UTC) volume: 24.227969800000004
2014-01-01 00:08:05 (DEBUG):    inserting candle 1437 (2013-12-31 23:57:00 UTC) volume: 33.217148850000015
2014-01-01 00:08:05 (DEBUG):    inserting candle 4 (2014-01-01 00:04:00 UTC) volume: 3.8902497499999997
2014-01-01 00:08:05 (DEBUG):    inserting candle 1438 (2013-12-31 23:58:00 UTC) volume: 31.217093780000003
2014-01-01 00:08:05 (DEBUG):    inserting candle 5 (2014-01-01 00:05:00 UTC) volume: 22.504872930000005
2014-01-01 00:08:05 (DEBUG):    inserting candle 1439 (2013-12-31 23:59:00 UTC) volume: 186.95011434999995
2014-01-01 00:08:05 (DEBUG):    Leftovers: 8
2014-01-01 00:08:06 (DEBUG):    inserting candle 6 (2014-01-01 00:06:00 UTC) volume: 149.45544371
2014-01-01 00:08:06 (INFO):     Processed trades, sleeping for a minute ...
2014-01-01 00:08:06 (DEBUG):    inserting candle 7 (2014-01-01 00:07:00 UTC) volume: 37.93444084000005
2014-01-01 00:08:06 (DEBUG):    Leftovers: 8
2014-01-01 00:08:06 (INFO):     Processed trades, sleeping for a minute ...
2014-01-01 00:09:05 (DEBUG):    Requested trade data from CEX.io ...
2014-01-01 00:09:06 (DEBUG):    Fetched 1001 new trades, from 2013-12-31 23:54:29 (UTC) to 2014-01-01 00:09:10 (UTC)
2014-01-01 00:09:06 (DEBUG):    minimum trade treshold: 2014-01-01 00:08:11 UTC
2014-01-01 00:09:06 (DEBUG):    processing 49 trade(s)
2014-01-01 00:09:06 (DEBUG):    inserting candle 8 (2014-01-01 00:08:00 UTC) volume: 47.31590448
2014-01-01 00:09:06 (DEBUG):    Leftovers: 9
2014-01-01 00:09:06 (INFO):     Processed trades, sleeping for a minute ...

[Neuro81]

yep I got the same

[askmike]

About the first error:

Gekko is supposed to take a different codepath whenever it goes over midnight, which it did not. I think I need more information (so with debug on for example) to determine why it behaved that way. I had 3 instances running overnight and they all kept running fine through the midnight limit.

About the second error:

Gekko needs a full history, this means without any gaps. If Gekko crashes, you restart it 30 min later and on the first fetch Gekko is not able to fill the 30 min gap the old data is marked as corrupted (not deleted) because Gekko cannot use it at all anymore.

[djmuk]

Mike - just a hunch but perhaps the bug happens when a fetch spans midnight but there aren't any trades after midnight? I'll leave debug on overnight & see what we catch...

The 2nd log was just to show what happened on a restart - I wasn't worried about the corrupt database message, although shouldn't it just fill that space with 'fake' candles?

[askmike]

So there are a bunch of scenarios which are all a pain to deal with:

when a fetch spans midnight but there aren't any trades after midnight?

Internally Gekko keeps track of days by this thing called current day which is always set to the latest trade date. So if it's 01:00 and the last trade was from 23:00 the current day is still yesterday.

There are other situations though, which should get resolved:

• If the history spans two days.
• If we have a history about yesterday 23:59 and get a fetch where we discard everything under 0:00. (this one was a bitch)

although shouldn't it just fill that space with 'fake' candles?

No: fake candles are only for minutes in which Gekko knows no trades happened, so if we get a trade for min 10 and min 12 in a fetch we know that nothing happened in 11. But if Gekko stops at 3:00 and starts at 4:00 with the oldest fetchable trade happened at 3:40 than Gekko considers the data corrupt because it cannot know what happened in the other 40 minutes and thus cannot create any sane advice out of it.

[djmuk]

Thanks for the explanation on fake candles.

[djmuk]

I was just going to add a comment that it ran fine over midnight when I found this:

2014-01-02 11:31:56 (DEBUG): inserting candle 690 (2014-01-02 11:30:00 UTC) volume: 0.4149838699999998
2014-01-02 11:31:56 (DEBUG): inserting candle 691 (2014-01-02 11:31:00 UTC) volume: 0.04709614000000001
2014-01-02 11:31:56 (DEBUG): Leftovers: 692
2014-01-02 11:31:57 (INFO): Processed trades, sleeping for 3 minutes ...
2014-01-02 11:34:55 (DEBUG): Requested trade data from CEX.io ...
2014-01-02 11:35:23 (DEBUG): cex.io returned an error, retrying..
2014-01-02 11:35:39 (DEBUG): Fetched 1001 new trades, from 2014-01-02 11:22:48 (UTC) to 2014-01-02 11:34:55 (UTC)
2014-01-02 11:35:39 (DEBUG): minimum trade treshold: 2014-01-02 11:32:11 UTC
2014-01-02 11:35:39 (DEBUG): processing 388 trade(s)
2014-01-02 11:35:39 (DEBUG): inserting candle 692 (2014-01-02 11:32:00 UTC) volume: 0.7022546199999996
2014-01-02 11:35:39 (DEBUG): inserting candle 693 (2014-01-02 11:33:00 UTC) volume: 77.98732104999992
2014-01-02 11:35:39 (DEBUG): Leftovers: 694
2014-01-02 11:35:39 (INFO): Processed trades, sleeping for 2 minutes ...
2014-01-02 11:38:04 (DEBUG): Requested trade data from CEX.io ...
2014-01-02 11:38:06 (DEBUG): Fetched 1001 new trades, from 2014-01-02 11:23:14 (UTC) to 2014-01-02 11:38:21 (UTC)
2014-01-02 11:38:06 (DEBUG): minimum trade treshold: 2014-01-02 11:34:55 UTC
2014-01-02 11:38:06 (DEBUG): processing 36 trade(s)

D:\Users\David\Documents\GitHub\gekko\core\databaseManager.js:569
throw 'Weird error...';
^
Weird error...

Update: cexio is down so that may have been the cause...

[askmike]

Very strange, my CEX.io instance is handling the crashed API correctly. I'll debug the code a little more.

[djmuk]

Sorry I wasn't clear, once I restarted gekko it DID correctly just return the 'cexio is down retrying' message...

[djmuk]

Testing current version - failed again last night both on CEX and BTCe but at different times and not at midnight...

[askmike]

This is getting frustating, I increased the logging around this error. Please posts logs when it happens again.

[djmuk]

and again - but only on BTCe, cexio ran over midnight OK......

2014-01-03 23:59:12 (DEBUG):    Leftovers: 1439
2014-01-03 23:59:12 (INFO):     Processed trades, sleeping for a minute ...
2014-01-04 00:00:12 (DEBUG):    Requested trade data from BTC-e ...
2014-01-04 00:00:12 (DEBUG):    Fetched 150 new trades, from 2014-01-03 23:57:14 (UTC) to 2014-01-04 00:00:27 (UTC)
2014-01-04 00:00:12 (DEBUG):    minimum trade treshold: 2014-01-03 23:59:16 UTC
2014-01-04 00:00:12 (DEBUG):    processing 87 trade(s)
2014-01-04 00:00:12 (DEBUG):    This batch includes trades for a new day.
2014-01-04 00:00:12 (DEBUG):    inserting candle 1439 (2014-01-03 23:59:00 UTC) volume: 20.602659500000005
2014-01-04 00:00:12 (DEBUG):    calced MACD properties for candle:
2014-01-04 00:00:12 (DEBUG):             short: 799.80252157
2014-01-04 00:00:12 (DEBUG):             long: 798.87481643
2014-01-04 00:00:12 (DEBUG):             macd: 0.11605908
2014-01-04 00:00:12 (DEBUG):             signal: 0.07571625
2014-01-04 00:00:12 (DEBUG):             macdiff: 0.04034284
2014-01-04 00:00:12 (DEBUG):    Creating a new daily database for day 2014-01-04
2014-01-04 00:01:12 (DEBUG):    Requested trade data from BTC-e ...
2014-01-04 00:01:13 (DEBUG):    Fetched 150 new trades, from 2014-01-04 00:00:25 (UTC) to 2014-01-04 00:01:26 (UTC)
2014-01-04 00:01:13 (DEBUG):    minimum trade treshold: 2014-01-04 00:00:27 UTC
2014-01-04 00:01:13 (DEBUG):    processing 120 trade(s)
1439 [ 0, 1 ]

Weird error 1

[iceydee]

This can be closed now?

[askmike]

I've still encountered it sometimes in a weird scenario.

But because of the big amount of edge cases I have now opted to rewrite some parts of the databaseManager to simplify some methods and make write tests for modularized pieces possible. After I've finished that I'll close this.

EDIT: I am now rewriting that as we speak.

[askmike]

Rewritten most of it, still errors in a situation I have not been able to figure out yet:

2014-01-11 00:59:13 (DEBUG):    done with this batch (1)
2014-01-11 00:59:13 (INFO): Processed trades, sleeping for a minute...
2014-01-11 01:00:13 (DEBUG):    Requested BTC/RUR trade data from BTC-e ...
2014-01-11 01:00:14 (DEBUG):    Fetched 150 new trades, from 2014-01-10 22:39:21 UTC to 2014-01-11 00:00:06 UTC
2014-01-11 01:00:14 (DEBUG):    minimum trade treshold: 2014-01-10 23:56:39 UTC
2014-01-11 01:00:14 (DEBUG):    processing 59 trade(s)
2014-01-11 01:00:14 (DEBUG):    fetch spans midnight
2014-01-11 01:00:14 (DEBUG):    Skipping creation of already loaded database 2014-01-10
2014-01-11 01:00:15 (DEBUG):    inserting candle 1436 (2014-01-10 23:56:00 UTC) volume: 0.01705531
2014-01-11 01:00:15 (DEBUG):    Going to publish to redis channel: small candle
2014-01-11 01:00:15 (DEBUG):    inserting candle 1437 (2014-01-10 23:57:00 UTC) volume: 0
2014-01-11 01:00:15 (DEBUG):    Going to publish to redis channel: small candle
2014-01-11 01:00:15 (DEBUG):    inserting candle 1438 (2014-01-10 23:58:00 UTC) volume: 0
2014-01-11 01:00:15 (DEBUG):    Going to publish to redis channel: small candle
2014-01-11 01:00:15 (DEBUG):    inserting candle 1439 (2014-01-10 23:59:00 UTC) volume: 22.556351299999992
2014-01-11 01:00:15 (DEBUG):    Going to publish to redis channel: small candle
2014-01-11 01:00:15 (DEBUG):    shifting past midnight
2014-01-11 01:00:15 (INFO): Processed trades, sleeping for a minute...
2014-01-11 01:01:14 (DEBUG):    Requested BTC/RUR trade data from BTC-e ...
2014-01-11 01:01:15 (DEBUG):    Fetched 150 new trades, from 2014-01-10 22:39:34 UTC to 2014-01-11 00:00:48 UTC
2014-01-11 01:01:15 (DEBUG):    minimum trade treshold: 2014-01-11 00:00:06 UTC
2014-01-11 01:01:15 (DEBUG):    processing 1 trade(s)

Weird error 2

I've added more debug data so I can pinpoint this asap. Because I wasn't able to reproduce with fake data somehow.