bitcoinvsalts / node-binance-trader

💰 Cryptocurrency Trading Strategy & Portfolio Management Development Framework for Binance. 🤖
https://bitcoinvsalts.com
MIT License
1.16k stars 381 forks source link

Signals no longer received #101

Closed realflash closed 3 years ago

realflash commented 3 years ago

I'm trying to debug an issue wherein I seem no longer to receive any signals. This is using master. I have a strategy favourited. With the trader running in node, if I watch the signals being transmitted by the strategy using the bva website, I can see that signals are happening but they aren't being received by the trader. This was working (thus my other bug about unknown pairs), but seems to have stopped.

The startup messages don't reveal much:

user@user-7490-mint:~/localdev/node-binance-trader$ npm run trader

> node-binance-trader@0.3.1 trader /home/user/localdev/node-binance-trader
> node ./src/trader.js

NBT auto trader running.
Exchange Minimums: [
  'ETHBTC',   'LTCBTC',   'BNBBTC',   'NEOBTC',  'QTUMETH', 'EOSETH',
  'SNTETH',   'BNTETH',   'BCCBTC',   'GASBTC',  'BNBETH',  'BTCUSDT',
  'ETHUSDT',  'HSRBTC',   'OAXETH',   'DNTETH',  'MCOETH',  'ICNETH',
  'MCOBTC',   'WTCBTC',   'WTCETH',   'LRCBTC',  'LRCETH',  'QTUMBTC',
  'YOYOBTC',  'OMGBTC',   'OMGETH',   'ZRXBTC',  'ZRXETH',  'STRATBTC',
  'STRATETH', 'SNGLSBTC', 'SNGLSETH', 'BQXBTC',  'BQXETH',  'KNCBTC',
  'KNCETH',   'FUNBTC',   'FUNETH',   'SNMBTC',  'SNMETH',  'NEOETH',
  'IOTABTC',  'IOTAETH',  'LINKBTC',  'LINKETH', 'XVGBTC',  'XVGETH',
  'SALTBTC',  'SALTETH',  'MDABTC',   'MDAETH',  'MTLBTC',  'MTLETH',
  'SUBBTC',   'SUBETH',   'EOSBTC',   'SNTBTC',  'ETCETH',  'ETCBTC',
  'MTHBTC',   'MTHETH',   'ENGBTC',   'ENGETH',  'DNTBTC',  'ZECBTC',
  'ZECETH',   'BNTBTC',   'ASTBTC',   'ASTETH',  'DASHBTC', 'DASHETH',
  'OAXBTC',   'ICNBTC',   'BTGBTC',   'BTGETH',  'EVXBTC',  'EVXETH',
  'REQBTC',   'REQETH',   'VIBBTC',   'VIBETH',  'HSRETH',  'TRXBTC',
  'TRXETH',   'POWRBTC',  'POWRETH',  'ARKBTC',  'ARKETH',  'YOYOETH',
  'XRPBTC',   'XRPETH',   'MODBTC',   'MODETH',  'ENJBTC',  'ENJETH',
  'STORJBTC', 'STORJETH', 'BNBUSDT',  'VENBNB',
  ... 1263 more items
]
Open Trades #: 1
Open Trades: { ONGUSDT608: true }

Additionally, where I use to see the message "NBT HUB => user strategies + trading setup updated" when I made changes on BVA, those messages no longer come through when I make a change.

Two questions:

  1. Should there always be a connection to https://nbt-hub.herokuapp.com:443 open, continuously? I'm seeing it be established but then drop after 4 minutes - no messages in the console. Still no strategy change messages even when it is connected.
  2. At line 80 of trader.js I see
    socket.on("connect", () => {
    console.log("Auto Trader connected.".grey)
    })

    This message is never emitted. Is that expected?

realflash commented 3 years ago

I've looked at this in Wireshark, and I see an HTTPS connection from node to AWS CloudFront (I now know Heroku is deployed on AWS so I'm assuming this is really Heroku), which is started when the trader first runs. Data is exchanged about 2s, and then my machine sends TCP Keep-Alives every second right up to 240s. Then it stops sending them, and the TCP connection is terminated.

dargmuesli commented 3 years ago

For me everything works with the latest stable release and Docker. I'm not using Heroku, so I'm afraid I cannot help there. In case this is still an issue, maybe @jsappme has an idea. If not, please close this issue.

realflash commented 3 years ago

Do you see that log message, "Auto Trader connected."?

dargmuesli commented 3 years ago

Yes, I do.

realflash commented 3 years ago

In a test I just did, my node process connected to 52.84.150.39. That isn't one of the IPs that is in the NS lookup answer to nbt-hub.herokuapp.com. Is it a known IP? Is it not in that set because of a CDN or LB set up in front of the app? Who knows the infrastructure well enough to know if that is a valid IP?

bitcoinvsalts commented 3 years ago

Thanks for reporting it. The NBT-hub is currently hosted with Heroku/AWS.The dyno does not have a static IP.

"Heroku Dynos can be any IP from an AWS Region"

Feel free to share some logs, I will take a deeper look if you still feel there is something suspicious. @.***

On Wed, Apr 7, 2021 at 8:56 AM Ian Gibbs @.***> wrote:

In a test I just did, my node process connected to 52.84.150.39. That isn't one of the IPs that is in the NS lookup answer to nbt-hub.herokuapp.com. Is it a known IP? Is it not in that set because of a CDN or LB set up in front of the app? Who knows the infrastructure well enough to know if that is a valid IP?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/jsappme/node-binance-trader/issues/101#issuecomment-814982731, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADGRD5MZUROYALY5Z3WD7XDTHRXAVANCNFSM4ZTAU24A .

dargmuesli commented 3 years ago

@realflash It should be enough to follow the https://github.com/jsappme/node-binance-trader/blob/master/docs/GETTING-STARTED.md guide to start the trader. Next to that document is a guide for manual setup. If those don't work, you'd have to specify the exact issue including steps we can take to reproduce the issue, thanks!

realflash commented 3 years ago

Here's the steps to reproduce:

cd node-binance-trader npm i --unsafe-perm cp .env.example .env

- Edit `.env` and only set the value `BVA_API_KEY`. Only virtual trades are selected for testing, so no need to connect to Binance (although it doesn't make a difference if you do put binance creds in).
- `npm run trader`

The installed version of nodejs is 10.9.0. The program runs without error. Margin pairs and minimums are printed to the screen. Open trades associated with the BVA account are correctly listed. **Problem 1**: The startup message ``Auto Trader connected`` is never emitted.

Run netstat to see active https connections:

$ sudo netstat -ntp | grep 443 tcp 0 0 192.168.1.98:35950 3.213.233.190:443 ESTABLISHED 13134/node
tcp 0 0 192.168.1.98:44442 52.84.150.39:443 ESTABLISHED 13134/node


Two connections are present. Wait 4 minutes. Run netstat again.

$ sudo netstat -ntp | grep 443 tcp 0 0 192.168.1.98:35950 3.213.233.190:443 ESTABLISHED 13134/node



**Problem 2**: One of the two https connections has disappeared. Is this expected?

Go to the BVA account and make a change to the followed strategies, or the amount traded, resulting in a user_payload signal being sent to the trader. **Problem 3**: The log message ``**NBT HUB => user strategies + trading setup updated`` is never emitted.

Wait for a trade signal to be emitted from a followed strategy. **Problem 4**: The signal isn't received at the trader. Nothing is output at the console.

Log files: https://gist.github.com/realflash/7a19826b207261bfc1f8a5309fcd40e9
realflash commented 3 years ago

If you wish, you can install a later version of nodejs:

curl https://raw.githubusercontent.com/creationix/nvm/master/install.sh | bash
source ~/.profile
nvm install --lts

It makes the console output a bit neater, but the end result is the same. The same situation can also be reproduced in this same VM using docker:

docker build -t jsappme/node-binance-trader .
docker run -d --name node-binance-trader -v "$PWD/.env:/srv/app/.env" jsappme/node-binance-trader npm run trader
docker logs node-binance-trader

(assuming you are in the same directory where you created the .env file earlier). The docker container output is identical to running it without docker.

Also reproduced in an AWS instance to rule out local network.

dargmuesli commented 3 years ago

Thank you very much for the detailed instructions! I'll try them shortly.

dargmuesli commented 3 years ago

I've now setup the virtual machine and executed the steps you provided. For me, Auto Trader connected is emitted, but between margin pairs and minimums output. It's just shortly visible, or visible by scrolling when using npm run trader |& less -F. Also the message NBT HUB => user strategies + trading setup updated is emitted on changes for me.

But you're correct, the tcp connection to 52.84.150.39 disappears. For me, it isn't required to receive signals from nbt though. I guess it's the connection to the Binance API that's not used anymore after retrieving the margin pairs and minimums.

Does https://bitcoinvsaltcoins.com/trader show your trader as off or on? If it's on, the label should be green, not yellow.

All in all, this issue seems to be specific to your network infrastructure or the bva API key you're using is incorrect. Please doublecheck that. Maybe try an external server by Hetzner or something alike.

dargmuesli commented 3 years ago

If your issue persists outside of your local setup, we can surely reopen this issue!

realflash commented 3 years ago

I have reproduced this in an AWS instance, so it isn't specific to my boring run-of-the-mill ADSL connection and router at home. The AWS instance is also in the DMZ, and you can use a web browser on it without issue, so nothing unusual there.

The BVA website shows the trader as off, which is consistent with the connected message being absent.

I've double checked the BVA key, and it is correct. If I intentionally make it wrong by changing a character, then I get this:

ERROR UpdateOpenTrades User Unknown #321 double check your BvA key

If I correct it again, this message goes away, but still no Auto Trader connected. This surely means that I am successfully reaching the infrastructure, in order for it to receive the key, check it and reject it? This is consistent with the fact that netstat shows the HTTPS connection has been established - state ESTABLISHED. The TCP connection set up completed successfully.

So:

Who has access to the infrastructure? Are there some server logs that can be examined?

bitcoinvsalts commented 3 years ago

I can check the log on the NBT hub side for you. What is your user name, or user id, or bva key?

On Fri, Apr 9, 2021 at 6:47 AM Ian Gibbs @.***> wrote:

I have reproduced this in an AWS instance, so it isn't specific to my boring run-of-the-mill ADSL connection and router at home. The AWS instance is also in the DMZ, and you can use a web browser on it without issue, so nothing unusual there.

The BVA website shows the trader as off, which is consistent with the connected message being absent.

I've double checked the BVA key, and it is correct. If I intentionally make it wrong by changing a character, then I get this:

ERROR UpdateOpenTrades User Unknown #321 double check your BvA key

If I correct it again, this message goes away, but still no Auto Trader connected. This surely means that I am successfully reaching the infrastructure, in order for it to receive the key, check it and reject it? This is consistent with the fact that netstat shows the HTTPS connection has been established - state ESTABLISHED. The TCP connection set up completed successfully.

So:

  • I can reach the BVA site
  • My authentication is valid
  • Something breaks after that point?

Who has access to the infrastructure? Are there some server logs that can be examined?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/jsappme/node-binance-trader/issues/101#issuecomment-816656984, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADGRD5M6WANRDPWQ2KBDYJDTH3ZNPANCNFSM4ZTAU24A .

bitcoinvsalts commented 3 years ago

can you add more log on your trader.js to see exactly where it breaks?

On Fri, Apr 9, 2021 at 6:49 AM Herve Fulchiron @.***> wrote:

I can check the log on the NBT hub side for you. What is your user name, or user id, or bva key?

On Fri, Apr 9, 2021 at 6:47 AM Ian Gibbs @.***> wrote:

I have reproduced this in an AWS instance, so it isn't specific to my boring run-of-the-mill ADSL connection and router at home. The AWS instance is also in the DMZ, and you can use a web browser on it without issue, so nothing unusual there.

The BVA website shows the trader as off, which is consistent with the connected message being absent.

I've double checked the BVA key, and it is correct. If I intentionally make it wrong by changing a character, then I get this:

ERROR UpdateOpenTrades User Unknown #321 double check your BvA key

If I correct it again, this message goes away, but still no Auto Trader connected. This surely means that I am successfully reaching the infrastructure, in order for it to receive the key, check it and reject it? This is consistent with the fact that netstat shows the HTTPS connection has been established - state ESTABLISHED. The TCP connection set up completed successfully.

So:

  • I can reach the BVA site
  • My authentication is valid
  • Something breaks after that point?

Who has access to the infrastructure? Are there some server logs that can be examined?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/jsappme/node-binance-trader/issues/101#issuecomment-816656984, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADGRD5M6WANRDPWQ2KBDYJDTH3ZNPANCNFSM4ZTAU24A .

realflash commented 3 years ago

Sure, where/what are the logging controls? Or do you mean write more logging statements in the code?

realflash commented 3 years ago

Sent you the key via email

dargmuesli commented 3 years ago

What was the solution?

bitcoinvsalts commented 3 years ago

Too many authentication failures (wrong bva key) triggering a ban of the user by the Hub.

realflash commented 3 years ago

There may have been some runs some weeks ago with no key specified when I was first setting up, are they cumulative over time? There can only have been one or two today when I was intentionally getting it wrong.

In any case it's still not working now.

bitcoinvsalts commented 3 years ago

there is still something wrong with your setup, it keeps on reconnecting...

2021-04-09T14:13:32.924124+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1 2021-04-09T14:13:38.335251+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1 2021-04-09T14:13:43.736971+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1 2021-04-09T14:13:49.088755+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1 2021-04-09T14:13:54.505197+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1 2021-04-09T14:13:59.908073+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

that would have been the reason for the ban.

dargmuesli commented 3 years ago

Maybe another instance of yours, @realflash, that still runs somewhere and that you might have forgotten about?

realflash commented 3 years ago

So one "run" of the trader with an incorrect key would look like multiple failed auth attempts and trigger the ban under the circumstances we are looking at?

I've tried in four places:

  1. On the command line on the Linux host (just run ps -ef and confirmed no node processes)
  2. In a docker on the Linux host (just run docker ps -a and found the container but it hasn't run for weeks
  3. In a VM on the Linux host (VM is stopped right now)
  4. In a VM on EC2 (VM is stopped right now)

To rule out another instance somewhere, I'm going to reboot this machine then do nothing between 14:30 UTC and 15:30 UTC. At 15:30 BST I will run the trader on the command line with the correct key for 15 minutes.

Could you please then check the logs to see that there are no connections between 14:30 and 15:30? That will confirm there are no other instances anywhere.

The weird thing here is the timings. The Auto trader connected message ought to appear within seconds of starting the script, but those connections are five minutes apart. Is it failing to connect for five minutes and trying again? That doesn't match with the TCP establishing OK, nor does it match with the authentication succeeding.

bitcoinvsalts commented 3 years ago

I don't see any authentication attempts with your user anymore for now. But before there were reconnection attempts within a few seconds apart not minutes.

2021-04-09T14:16:05.864092+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:11.215781+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:16.588375+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:21.981475+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:27.388680+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:32.777990+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:38.192196+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:43.591321+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:48.968172+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:54.332149+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

2021-04-09T14:16:59.735015+00:00 app[web.1]: CONNECTION CLIENT :: 1691 stockproc Northampton GB 0.3.1

On Fri, Apr 9, 2021 at 8:27 AM Ian Gibbs @.***> wrote:

So one "run" of the trader with an incorrect key would look like multiple failed auth attempts and trigger the ban under the circumstances we are looking at?

I've tried in four places:

  1. On the command line on the Linux host (just run ps -ef and confirmed no node processes)
  2. In a docker on the Linux host (just run docker ps -a and found the container but it hasn't run for weeks
  3. In a VM on the Linux host (VM is stopped right now)
  4. In a VM on EC2 (VM is stopped right now)

To rule out another instance somewhere, I'm going to reboot this machine then do nothing between 14:30 UTC and 15:30 UTC. At 15:30 BST I will run the trader on the command line with the correct key for 15 minutes.

Could you please then check the logs to see that there are no connections between 14:30 and 15:30? That will confirm there are no other instances anywhere.

The weird thing here is the timings. The Auto trader connected message ought to appear within seconds of starting the script, but those connections are five minutes apart. Is it failing to connect for five minutes and trying again? That doesn't match with the TCP establishing OK, nor does it match with the authentication succeeding.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/jsappme/node-binance-trader/issues/101#issuecomment-816721914, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADGRD5OIHDIRCGSX427AIEDTH4FERANCNFSM4ZTAU24A .

realflash commented 3 years ago

That's me mis-reading the seconds field in the log file for minutes.I'm rebooted now with nothing running. If you can check again at 15:30 I'd be grateful.

Meanwhile I will look into putting an HTTPS proxy in between the trader and BVA so that we can get some proper debug logging .

bitcoinvsalts commented 3 years ago

Perfect. Yes I will keep on monitoring the situation.

On Fri, Apr 9, 2021 at 8:40 AM Ian Gibbs @.***> wrote:

That's me mis-reading the seconds field in the log file for minutes.I'm rebooted now with nothing running. If you can check again at 14:30 I'd be grateful.

Meanwhile I will look into putting an HTTPS proxy in between the trader and BVA so that we can get some proper debug logging .

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/jsappme/node-binance-trader/issues/101#issuecomment-816730527, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADGRD5IX5CGOIUJA3QW6NADTH4GVHANCNFSM4ZTAU24A .

realflash commented 3 years ago

So I think have worked this out. Three factors have converged to create a hole I largely dug myself into. Thank you both for your assistance and patience in helping me get to the bottom of this.

Failure 1: When I signed up at BVA, there was a typo in my email address. This wasn't a direct issue as I still had a valid BVA key, but when the account got locked (I'm not sure it's clear how that happened some time ago), @jsappme emailed me to tell me but I obviously didn't get it. Had I got it, then after unlocking my docker container would have worked and I could then have deduced failure 2. I'm going to create a new account with the correct email address so if you want to/can destroy the current one please do.

Failure 2: The very first time I checked out, I missed out on the instruction npm i --unsafe-perm. Instead when trying to run I got various missing module errors until the program ran without errors. Somehow I ended up with lots of modules missing, and the program still starting without error. After I ran npm i, everything was installed and the trader now functions correctly (since the account is also unlocked). I've tried to reproduce this a VM by intentionally missing out the npm i and installing according to errors, but after one sudo npm install express all the other modules are installed and it works. I don't think I'll be able to repeat this.

Failure 3 Locked account. Possibly some combination of testing I did some weeks ago when this first failed caused the account to be locked, possibly something else happened. There's no feedback from the trader when the account is locked and it fails to do whatever it should do. I'm guessing @jsappme found out via some security warning? Is an enhancement to print an error message similar to that printed when you have got the BVA key wrong appropriate?

I learnt during this process that you can get socket.io to print out debug information by doing

DEBUG=* node ./src/trader.js

Then you can see the message contents without having to do an HTTPS MITM attack.

I can now head back to the USDT branch and try to get that working.

bitcoinvsalts commented 3 years ago

Thanks for your feedback, I am glad it's working.

dargmuesli commented 3 years ago

https://socket.io/docs/v4/client-socket-instance/ says there is a connect_error event. @jsappme could you try if this would respond to such an error as described in this issue? We could then add logging there.