6x Last Buy Price about binance-trading-bot

[dasbts]

There's seemingly no Wiki entry about reverting an upgrade. Now I also got two random of these messages:
Unable to fully release the lock on resource "redlock:trailing-trade-symbols:FTMBTC-latest-candle".
Unable to fully release the lock on resource "redlock:trailing-trade-symbols:BCHBTC-latest-candle".

Even tho I am currently not trading with BTC as base.

[dasbts]

Maybe most strange is seeing the commits that's been made, they don't seem like changes which could break the bot.

I looked into ways of reverting both git pull and dockers image, but I'm not sure, is it possible to change the server yaml to an earlier version than latest? I have backed up the DB before updating, but also made some more trades after. Not sure if revert without DB restore would work.

[dasbts]

This makes currently trailing trades stop updating too as soon as I get the "Unable to fully release the lock on resource "redlock:trailing-trade-symbols:UTKBTC-latest-candle"."

[rando128]

Can you try to reboot your server to reset your memory resources?

…

On Wed, Mar 29, 2023 at 10:37 AM dasbts ***@***.***> wrote: This makes currently trailing trades stop updating too as soon as I get the "Unable to fully release the lock on resource "redlock:trailing-trade-symbols:UTKBTC-latest-candle"." — Reply to this email directly, view it on GitHub <#618 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AALMG667HM6XQOJD3QBZNNLW6PYGJANCNFSM6AAAAAAWK7PN2I> . You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

[dasbts]

It either happened with the two Commits on Feb 8, 2023 or later than that as I have been making pulls every month.

[dasbts]

Rebooted the server before going to sleep yesterday, woke up to the same issue. Trying that again now.

Also experienced this again according to Slack:
#617

Did this as well but not sure if it's gonna be the same as in the docker-image:
git reset --keep HEAD@{1}

Trying to pull this:
https://hub.docker.com/layers/chrisleekr/binance-trading-bot/0.0.97/images/sha256-729899f3ccc0afa266890349655caa8fd9a9ceb09034e7463b6faae29c9ffa0a?context=explore

[dasbts]

Same issue on 0.0.97 docker image. 0.0.96 won't even start and I had to --remove-orphan when using docker-compose pull too..

[dasbts]

Is there no way to downgrade to 0.0.96? I'm having sell orders currently trailing and every 20 minutes or so it just freezes leading to having to restart. :(

[dasbts]

Seems like as soon as this happens, the ticker stops working for the token the message is about until restarting the bot. Kind of just like in 0.0.96 where the menu to show daily, monthly, or all profits also locked up previously when receiving the message (but for what I think was "all-symbols", now it's individual tickers), something which made the whole GUI inaccessible, but then it at least traded, now it just freezes the ticker.

Found this. They recommend upgrading Redlock (maybe even Redis image itself?) as this have been rewritten to fix issues. Thus, it is just closed and was never addressed. Someone managed to increase lock time to fix the issue, but I would agree that upgrading would be good.
mike-marcacci/node-redlock#65

How much work would be required, and how can I help to make such change?

[dasbts]

I haven't been developing docker images myself, so not sure if I have to build before changes will be made, but tried changing this PR parts to 1500 instead of 1000, I suppose that's the lock time that they talked about in the thread.
https://github.com/chrisleekr/binance-trading-bot/pull/522/files

[dasbts]

Maybe i can download the 0.0.96 version? The thing is, I have both entered and closed some positions since my last backup of the database...

Currently the bot is completely broken since 0.0.97. Let me know if I can help, working as a consultant in finance and IT daily doing quite some programming.

Seems like this also freezes my server as I'm not able to connect to it through TeamViewer all night and these errors ha en been occurring every 2-5 seconds for mainly tokens I am not even trading/monitoring.

[chrisleekr]

Hi @dasbts

I am sorry for the late reply. I am swamped, so I couldn't have a chance to look it up.

I think, for some reason, the data is messed up. Without a detailed log, I won't be able to troubleshoot the issue.

So I agree with you about downgrading. So good that you had a backup as well.

To downgrade, please follow the steps:

1. Shutdown docker containers with volume deletion.

   $ docker-compose down -v
   

2. Update docker-compose.server.yml
   • image: chrisleekr/binance-trading-bot:latest to image: chrisleekr/binance-trading-bot:0.0.96
   • image: chrisleekr/binance-trading-bot:tradingview to image: chrisleekr/binance-trading-bot:tradingview-0.0.96
3. Start docker containers

   $ docker-compose -f docker-compose.server.yml up -d
   

This should launch the bot with a clean database. Then you can use your backup to restore.

However, it means you are tied to this 0.0.96 version and won't be able to upgrade.
If you are happy with it, that is fine. But if you want to upgrade in the future, I suggest that you launch the bot with the latest version and a clean database. Then set the last buy price manually.

For the redlock error, can you tell me what server specification you run? Especially disk speed.

[dasbts]

Ok, so it seems like the ENOBUFS error is related to memory, so I did some performance upgrades I seem to have missed.

First off, I'm running Debian 11 with not so good laptop Acer Aspire 5750 which only has 6 GB RAM and a 640 GB HDD. The HDD seem to have 2500 MB/s speed when running hdparm test after setting APM to 254 to get more performance, but I don't trust that result 100%. I previously only had a swap file, but have now read up on and enabled zram-tools (zram-config on newer Debian) which allowed compressing the RAM. I have about 25% free RAM at all time when running the bot together with some other homebrew applications.

This seem to have worked partially, but then I realized, I should print out the logs for redis since redlock is connected to this.
1:M 31 Mar 2023 15:15:07.655 # WARNING: The TCP backlog setting of 65536 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 1024.
1:M 31 Mar 2023 15:15:07.655 # Server initialized
1:M 31 Mar 2023 15:15:07.655 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.

So, I have added the following to my /etc/sysctl.conf:
fs.inotify.max_user_watches=254800
vm.vfs_cache_pressure=300
vm.swappiness=100
vm.dirty_background_ratio=1
vm.dirty_ratio=50
vm.overcommit_memory = 1

I also added to the cache.js file:
await redlock.lock(redlock:${key}, 1500);
Instead of the 1000 added in the following commit:
98be882

In docker-compose.server.yml I also changed the following which was suggested to fix the TCP backlog setting warning:
sysctls:
net.core.somaxconn: 65535
It was previously 1024 on the binance-redis image. I am a bit confused tho, shouldn't this be at least 65536 according to the warning? Also looking in /proc/sys/net/core/somaxconn it is 4096.

Then, since it is ioredis we are working with in the cache.js, I figured, why not look into the config more in depth since people were posting about params in the redlock issue that is about this same thing about not fully releasing lock, I found I could add the following params. Not sure if any/all is needed, or if I chose a too high value such as for maxRetriesPerRequest, but doing it to test:
keepalive: true,
retryStrategy(times) {
const delay = Math.min(times * 50, 2000);
return delay;
},
maxRetriesPerRequest: 50,
enableAutoPipelining: true,
showFriendlyErrorStack: true

const redlock I also changed to:
retryCount: 20,
retryDelay: 300

Oh, and I also installed a Debian package called tuned-adm with the profile "throughput-performance".

Will update on any progress. So far it seem to be way more stable, but cannot say for certain yet. At least I am able to keep the GUI open for longer times.

[dasbts]

Gonna keep digging ASAP, got a bit much to do outside this too, but I believe it would be good to somehow make it keep retrying, as whenever the redlock fails, it will just freeze the element which is locked seemingly forever. Either that, or it just keeps awaiting the lock.release as it seem the code is made to do so, and if it's never released due to something that only partially unlocks the element, or if it's just never getting that await to complete, I guess that's why it freezes.

[dasbts]

Ok so after trying a lot I might have figured it out.

First off, it was seemingly not correct to add the now commented code to the redis const:
const redis = new Redis({ host: config.get('redis.host'), port: config.get('redis.port'), password: config.get('redis.password'), db: config.get('redis.db') // keepalive: true, // retryStrategy(times) { // const delay = Math.min(times * 50, 2000); // return delay; // }, // maxRetriesPerRequest: 50, // enableAutoPipelining: true, // showFriendlyErrorStack: true });

I think this is not introduced until later releases than the binance-bot uses. So, instead, I tried updating redlock with NPM to the nevest beta. I added a 5 times retry of 1s each try for each "await lock.release()", changed all "redlock.lock" to "redlock.acquire", and all "lock.unlock" to "lock.release".

I also had to change "const Redlock = require('redlock');" to "const { default: Redlock } = require("redlock");", something which seem to become deprecated in the future.

So far this seem to be ok, will do some testing for a day or two first before commiting. Thinking of trying instead of X retries, just extend the lock with 1 second or such and retry until it works to release.

HOWEVER, this seemingly introduced a new bug:
mike-marcacci/node-redlock#168
I "solved" this by temporarily adding "if (err.message.includes('quorum'))" to the handleError in error-handler.js.
"I believe this is a bug in the v5 implementation. When you attempt to set a lock using acquire() and the resource is locked, Redlock will throw an ExecutionError, but it should throw a ResourceLockedError (as it did in the previous version)."

There's also an alternative called "redlock.using" which allows adding:
// The minimum remaining time on a lock before an extension is automatically
// attempted with the using API.
automaticExtensionThreshold: 500, // time in ms

IF this works, the only thing I'm worried about is if something is locked, and it keeps triggering for example a buy order, does this mean there is a queue building up with multiple buy scenarios happening? Since that was the reason this issue was made. I think either that is still a possibility, or since I used to have poor server performance prior to tuning, maybe the RAM messed up the buy order?

By the way. I retract the ENOBUFS (which I even closed the issue for before) statement that it seem to be RAM (which is usually the case). I have optimized so have currently about 30% free all the time. However, it seems like tuning the CPU to network-performance profile instead and that seems more stable. This after I observed the error message again when CPU usage was high.
#617
I did get this once again recently, but no redlock error with it as it previously did, so that's some hope. Found this setting to also try if someone happens to get ENOBUFS on Ubuntu:
net.ipv4.xfrm4_gc_thresh=32768
https://serverfault.com/questions/614453/no-buffer-space-available-on-connect
https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?id=528555d05bde69c436bb0126ea95635da24d889e

[dasbts]

Ok, so I received no errors after the previous attempt with awaiting the lock.release. However, this made the ticker stop completely with the GUI still working and it saying there was no update for 5 minutes (with the clock being stopped hours ago). Still an improvement since before the whole GUI would not be accessible.

I'm going to look through the commits again since previously it wasn't the tickers that stopped working, but rather for example the filter of profits between D, M, Y, all. If that can be fixed I believe there would not be any need for restarting the bot anymore.

The strange thing is I also then noticed that when losing internet, every open websocket seemingly breaks. Miight need a quick websocket check if there haven't been any activity for some minutes.

[chrisleekr]

@dasbts

First of all, I really appreciate it if you follow the bug template if you submit the bug.

Is this continuously happening or it was just once off?

And if it is happening, try to get the log and export it.

That will tell what exactly happened.

I will close the issue for now. If you find it is happening again, please re-open and upload the log.

[dasbts]

It happened once thankfully as otherwise I would have to switch out this bot, but since then I have also updated redlock, migrated the redlock by changing all "redlock.lock" to "redlock.acquire", and all "lock.unlock" to "lock.release". I also added a 30 times retry for each "await lock.release()" with 0.5 second sleep between each try. This have solved any issues with the GUI not responding or opening for me as well.
Oh and the migration also required changing the import from const Redlock = require('redlock'); to const { default: Redlock } = require("redlock");

I also added the optimization to the Debian server as mentioned above and in general have much better performance now so hopefully it won't happen again. Oh and I added to the error handler to ignore ENOBUFS in all three const/functions that are there, that way, ENOBUFS won't stop the bot or any of it's components as I have seen this error even when there are clearly enough RAM.

About the logs, I believe I checked those when this happened, but not 100% sure, anyway it is very strange that it did only update the lastbuyprice but not the amount and number of grids/trades used in the GUI.

[dasbts]

@chrisleekr I had a similar thing happen today. Not 6x Last Buy Price, but 0. Luckily it closed at a profit, but it now shows wrong in the GUI of the bot trade results, as it thinks the buy price was 0.

It was a trade from about 3-4 years ago which I in the bot set manual last buy price for.

Here is the Slack log:

Jeff Bezos
APP 00:11
(22:11:52.776) TOMOUSDT Sell Action Grid Trade #1: STOP_LOSS_LIMIT

• Order Params:
  {
  "symbol": "TOMOUSDT",
  "side": "sell",
  "type": "STOP_LOSS_LIMIT",
  "quantity": 200.8,
  "stopPrice": 2.1805,
  "price": 2.1695,
  "timeInForce": "GTC"
  }
• Current API Usage: 41

00:11
(22:11:53.152) Execution failed:
Job: Trailing Trade
Code: -2010
Message:
Stop price would trigger immediately.
Stack:
Error: Stop price would trigger immediately.
at /srv/node_modules/binance-api-node/dist/http-client.js:102:17
at runMicrotasks ()
at processTicksAndRejections (internal/process/task_queues.js:95:5)
at async execute (/srv/dist/server.js:1:45846)
at async /srv/dist/server.js:1:9384
at async errorHandlerWrapper (/srv/dist/server.js:1:91955)
at async Object.execute [as processFn] (/srv/dist/server.js:1:8088)
at async i (/srv/dist/server.js:1:78097)
at async Object.execute (/srv/dist/server.js:1:78669)

• Current API Usage: 42
  00:11
  (22:11:56.191) TOMOUSDT Sell Action Grid Trade #1: STOP_LOSS_LIMIT
• Order Params:
  {
  "symbol": "TOMOUSDT",
  "side": "sell",
  "type": "STOP_LOSS_LIMIT",
  "quantity": 200.8,
  "stopPrice": 2.2142,
  "price": 2.203,
  "timeInForce": "GTC"
  }
• Current API Usage: 42
  00:11
  (22:11:58.573) TOMOUSDT Sell Action Grid Trade #1 Result: STOP_LOSS_LIMIT
• Order Result:
  {
  "symbol": "TOMOUSDT",
  "orderId": 589382949,
  "orderListId": -1,
  "clientOrderId": "IFyWNmzA9ID7BZOJDn9fiK",
  "transactTime": 1685311916481
  }
• Current API Usage: 56
  00:12
  (22:12:01.893) TOMOUSDT Sell Action Grid Trade #1: STOP_LOSS_LIMIT
• Order Params:
  {
  "symbol": "TOMOUSDT",
  "side": "sell",
  "type": "STOP_LOSS_LIMIT",
  "quantity": 200.8,
  "stopPrice": 2.2983,
  "price": 2.2867,
  "timeInForce": "GTC"
  }
• Current API Usage: 11
  00:12
  (22:12:04.490) TOMOUSDT Sell Action Grid Trade #1 Result: STOP_LOSS_LIMIT
• Order Result:
  {
  "symbol": "TOMOUSDT",
  "orderId": 589385251,
  "orderListId": -1,
  "clientOrderId": "8yeUrA9hT0VwPiz4RQGniP",
  "transactTime": 1685311922181
  }
• Current API Usage: 25
  00:15
  (22:15:17.284) TOMOUSDT SELL Grid Trade #1 Order Filled: STOP_LOSS_LIMIT
• Order Result:
  {
  "symbol": "TOMOUSDT",
  "orderId": 589385251,
  "orderListId": -1,
  "clientOrderId": "8yeUrA9hT0VwPiz4RQGniP",
  "transactTime": 1685311922192,
  "currentGridTradeIndex": 0,
  "status": "FILLED",
  "type": "STOP_LOSS_LIMIT",
  "side": "SELL",
  "stopPrice": "2.29830000",
  "price": "2.28670000",
  "origQty": "200.80000000",
  "cummulativeQuoteQty": "459.16936000",
  "executedQty": "200.80000000",
  "isWorking": true,
  "updateTime": 1685311922192,
  "timeInForce": "GTC",
  "icebergQty": "0.00000000",
  "time": 1685311922181,
  "workingTime": 1685311922189,
  "origQuoteOrderQty": "0.00000000",
  "selfTradePreventionMode": "NONE"
  }
• Current API Usage: 130
  00:15
  (22:15:20.056) TOMOUSDT Action - Removed last buy price:
• Message: All sell orders are executed. Delete last buy price.
  {
  "lastBuyPrice": 2.09155804,
  "currentPrice": 2.2775,
  "minNotional": "10.00000000",
  "openOrders": []
  }
• Current API Usage: 133
  00:15
  (22:15:20.635) TOMOUSDT Profit:
• Profit: 459.16936
• ProfitPercentage: 0
• Total Buy Amount: 0
• Total Sell Amount: 459.16936

The log in the GUI was autodeleted due to the default config, will have to increase this for future events.

[dasbts]

Still experiencing this. :(