Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Wallet server hangs after trying to send out funds #180

Open
Giszmo opened this issue Jun 2, 2021 · 2 comments
Open

Wallet server hangs after trying to send out funds #180

Giszmo opened this issue Jun 2, 2021 · 2 comments

Comments

@Giszmo
Copy link

Giszmo commented Jun 2, 2021

This issue was originally reported to BTCPayServer

Describe the bug

After trying to send funds using the spark-wallet, the web interface stops working with an "Error: Gateway Timeout" and the process spark-wallet runs at 100% CPU until I kill it.

Killing spark-wallet with SITTERM fixes the spark UI.

To Reproduce the bug

Unfortunately this issue is not 100% reproducible. It happened, I rebooted the machine as restarting the btcpayserver from the webinterface only resulted in the whole thing responding 502 and I ran into the state again. Killing only spark-wallet fixed it then and after that, sending funds worked or not but the server didn't hang again.

  1. Try to send all funds from your spark-wallet to a Phoenix invoice without amount or label.

Your BTCPay Environment (please complete the following information):

  • BTCPay Server Version: v1.1.2.0
  • Deployment Method: Docker
  • Browser: FF

Logs (if applicable)

# docker logs --tail 300 generated_clightning_bitcoin_spark_1
POST /rpc 200 2.683 ms - -
LightningError: failed: WIRE_INCORRECT_OR_UNKNOWN_PAYMENT_DETAILS (reply from remote)
    at createError (/opt/spark/node_modules/error/typed.js:40:22)
    at LightningClient.once.res (/opt/spark/node_modules/clightning-client/index.js:107:28)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:116:13)
    at LightningClient.emit (events.js:211:7)
    at Interface.LightningClient.rl.on.line (/opt/spark/node_modules/clightning-client/index.js:62:17)
    at emitOne (events.js:116:13)
    at Interface.emit (events.js:211:7)
    at Interface._onLine (readline.js:280:10)
    at Interface._normalWrite (readline.js:422:12)
RangeError: Invalid status code: pending
    at ServerResponse.writeHead (_http_server.js:200:11)
    at ServerResponse.writeHead (/opt/spark/node_modules/on-headers/index.js:55:19)
    at ServerResponse.writeHead (/opt/spark/node_modules/compression/node_modules/on-headers/index.js:44:26)
    at ServerResponse._implicitHeader (_http_server.js:191:8)
    at ServerResponse.end (/opt/spark/node_modules/compression/index.js:103:14)
    at ServerResponse.send (/opt/spark/node_modules/express/lib/response.js:221:10)
    at ServerResponse.json (/opt/spark/node_modules/express/lib/response.js:267:15)
    at ServerResponse.send (/opt/spark/node_modules/express/lib/response.js:158:21)
    at /opt/spark/dist/app.js:117:43
    at Layer.handle_error (/opt/spark/node_modules/express/lib/router/layer.js:71:5)
POST /rpc 500 15364.779 ms - 148
POST /rpc 200 1.803 ms - 399
POST /rpc 200 3.796 ms - -
POST /rpc 200 1.802 ms - 605
POST /rpc 200 4885.175 ms - 414
POST /rpc 200 3.439 ms - -
POST /rpc 200 2.219 ms - 605
POST /rpc 200 2.432 ms - -
POST /rpc 200 1.731 ms - 399
POST /rpc 200 1.675 ms - 605
POST /rpc 200 2.011 ms - 744
POST /rpc 200 4.875 ms - -
LightningError: Ran out of routes to try after 25 attempts: see `paystatus`
    at createError (/opt/spark/node_modules/error/typed.js:40:22)
    at LightningClient.once.res (/opt/spark/node_modules/clightning-client/index.js:107:28)
    at Object.onceWrapper (events.js:315:30)
    at emitOne (events.js:116:13)
    at LightningClient.emit (events.js:211:7)
    at Interface.LightningClient.rl.on.line (/opt/spark/node_modules/clightning-client/index.js:62:17)
    at emitOne (events.js:116:13)
    at Interface.emit (events.js:211:7)
    at Interface._onLine (readline.js:280:10)
    at Interface._normalWrite (readline.js:422:12)
POST /rpc 500 241.992 ms - -
Lightning client connection closed, reconnecting
Lightning client connection closed, reconnecting
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET /stream?access-key=topsecret 200 1.482 ms - -
GET / 304 0.967 ms - -
GET /style.css 304 2.761 ms - -
GET /load-theme.js 304 2.053 ms - -
GET /app.js 304 1.512 ms - -
GET /swatch/dark/bootstrap.min.css 200 2.431 ms - -
GET /fonts/typeface-open-sans/index.css 200 2.747 ms - -
GET /lib/instascan.js 304 1.023 ms - -
GET /worker.js 200 1.971 ms - -
GET /?access-key=topsecret 301 0.870 ms - 66
GET /redir 200 0.474 ms - -
GET / 304 0.828 ms - -
GET /load-theme.js 304 1.723 ms - -
GET /app.js 304 1.665 ms - -
GET /style.css 304 1.013 ms - -
GET /swatch/dark/bootstrap.min.css 304 0.937 ms - -
GET /fonts/typeface-open-sans/index.css 304 2.149 ms - -
GET /lib/instascan.js 304 0.919 ms - -
GET /fonts/typeface-open-sans/files/open-sans-latin-300.woff2 304 1.628 ms - -
GET /fonts/typeface-open-sans/files/open-sans-latin-400.woff2 304 1.104 ms - -
GET /worker.js 200 1.428 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET /stream?access-key=topsecret 200 1.501 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET /stream?access-key=topsecret 200 0.934 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET / 304 0.941 ms - -
GET /load-theme.js 304 1.784 ms - -
GET /app.js 304 1.110 ms - -
GET /style.css 304 1.619 ms - -
GET /swatch/dark/bootstrap.min.css 304 0.953 ms - -
GET /fonts/typeface-open-sans/index.css 304 0.925 ms - -
GET /lib/instascan.js 304 0.724 ms - -
GET /worker.js 200 1.299 ms - -
POST /rpc - - ms - -
GET /stream?access-key=topsecret 200 0.897 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET /?access-key=topsecret 301 0.701 ms - 66
GET /redir 200 0.444 ms - -
GET / 304 0.809 ms - -
GET /load-theme.js 304 2.624 ms - -
GET /app.js 304 2.002 ms - -
GET /style.css 304 1.474 ms - -
GET /swatch/dark/bootstrap.min.css 304 0.815 ms - -
GET /fonts/typeface-open-sans/index.css 304 0.915 ms - -
GET /lib/instascan.js 304 0.938 ms - -
GET /fonts/typeface-open-sans/files/open-sans-latin-300.woff2 304 1.644 ms - -
GET /fonts/typeface-open-sans/files/open-sans-latin-400.woff2 304 1.145 ms - -
GET /manifest-maybesecret/manifest.json 304 0.954 ms - -
GET /worker.js 200 3.018 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET /stream?access-key=topsecret 200 0.848 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET / 304 0.756 ms - -
POST /rpc - - ms - -
GET /load-theme.js 304 3.506 ms - -
GET /app.js 304 2.866 ms - -
GET /style.css 304 1.316 ms - -
GET /swatch/dark/bootstrap.min.css 304 0.913 ms - -
GET /fonts/typeface-open-sans/index.css 304 0.831 ms - -
GET /lib/instascan.js 304 0.886 ms - -
GET /worker.js 200 2.259 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET /stream?access-key=topsecret 200 0.823 ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
POST /rpc - - ms - -
GET / 200 0.832 ms - 809
GET /load-theme.js 304 1.697 ms - -
GET /app.js 304 1.410 ms - -
GET /style.css 200 4.701 ms - -
GET /swatch/dark/bootstrap.min.css 200 1.268 ms - -
GET /fonts/typeface-open-sans/index.css 200 1.237 ms - -
GET /lib/instascan.js 304 1.260 ms - -
GET /worker.js 200 1.233 ms - -

Setup Parameters

# . btcpay-setup.sh -i

-------SETUP-----------
Parameters passed:
BTCPAY_PROTOCOL:https
BTCPAY_HOST:---
BTCPAY_ADDITIONAL_HOSTS:
REVERSEPROXY_HTTP_PORT:80
REVERSEPROXY_HTTPS_PORT:443
REVERSEPROXY_DEFAULT_HOST:none
LIBREPATRON_HOST:
ZAMMAD_HOST:
WOOCOMMERCE_HOST:
BTCTRANSMUTER_HOST:
BTCPAY_ENABLE_SSH:true
BTCPAY_HOST_SSHKEYFILE:
LETSENCRYPT_EMAIL:
NBITCOIN_NETWORK:mainnet
LIGHTNING_ALIAS:
BTCPAYGEN_CRYPTO1:btc
BTCPAYGEN_CRYPTO2:
BTCPAYGEN_CRYPTO3:
BTCPAYGEN_CRYPTO4:
BTCPAYGEN_CRYPTO5:
BTCPAYGEN_CRYPTO6:
BTCPAYGEN_CRYPTO7:
BTCPAYGEN_CRYPTO8:
BTCPAYGEN_CRYPTO9:
BTCPAYGEN_REVERSEPROXY:nginx
BTCPAYGEN_LIGHTNING:clightning
BTCPAYGEN_ADDITIONAL_FRAGMENTS:opt-save-storage-s
BTCPAYGEN_EXCLUDE_FRAGMENTS:
BTCPAY_IMAGE:
ACME_CA_URI:production
TOR_RELAY_NICKNAME: 
TOR_RELAY_EMAIL: 
PIHOLE_SERVERIP: 
----------------------
Additional exported variables:
BTCPAY_DOCKER_COMPOSE=/root/btcpayserver-docker/Generated/docker-compose.generated.yml
BTCPAY_BASE_DIRECTORY=/root
BTCPAY_ENV_FILE=/root/.env
BTCPAYGEN_OLD_PREGEN=false
BTCPAY_SSHKEYFILE=/datadir/host_id_rsa
BTCPAY_SSHAUTHORIZEDKEYS=/datadir/host_authorized_keys
BTCPAY_HOST_SSHAUTHORIZEDKEYS:/root/.ssh/authorized_keys
BTCPAY_SSHTRUSTEDFINGERPRINTS:
BTCPAY_CRYPTOS:btc
BTCPAY_ANNOUNCEABLE_HOST:---
----------------------

BTCPay Server environment variables successfully saved in /etc/profile.d/btcpay-env.sh

BTCPay Server docker-compose parameters saved in /root/.env

Using default tag: latest
latest: Pulling from btcpayserver/docker-compose-generator
Digest: sha256:603ab55cd906cff7176acf800fbe8b6e900a5c12af94e2948ea9bbaa7264b58a
Status: Image is up to date for btcpayserver/docker-compose-generator:latest
docker.io/btcpayserver/docker-compose-generator:latest
Crypto: btc
Lightning: clightning
ReverseProxy: nginx
Generating /app/Generated/docker-compose.generated.yml
Selected fragments:
	nginx
	btcpayserver
	bitcoin
	bitcoin-clightning
	opt-save-storage-s
	btcpayserver-nginx
	postgres
	nbxplorer
	nginx-https
	opt-add-tor
Generated /app/Generated/pull-images.sh
Generated /app/Generated/save-images.sh
Generated /app/Generated/docker-compose.generated.yml

Adding btcpayserver.service to systemd
BTCPay Server systemd configured in /etc/systemd/system/btcpayserver.service

BTCPay Server starting... this can take 5 to 10 minutes...
BTCPay Server started
generated_bitcoin_rtl_1 is up-to-date
tor is up-to-date
generated_nbxplorer_1 is up-to-date
nginx is up-to-date
generated_postgres_1 is up-to-date
btcpayserver_bitcoind is up-to-date
tor-gen is up-to-date
btcpayserver_clightning_bitcoin is up-to-date
generated_clightning_bitcoin_rest_1 is up-to-date
generated_clightning_bitcoin_charge_1 is up-to-date
generated_clightning_bitcoin_spark_1 is up-to-date
generated_btcpayserver_1 is up-to-date
nginx-gen is up-to-date
letsencrypt-nginx-proxy-companion is up-to-date
Installed bitcoin-cli.sh to /usr/local/bin: Command line for your Bitcoin instance
Installed bitcoin-lightning-cli.sh to /usr/local/bin: Command line for your Bitcoin C-Lightning instance
Installed btcpay-clean.sh to /usr/local/bin: Command line for deleting old unused docker images
Installed btcpay-down.sh to /usr/local/bin: Command line for stopping all services related to BTCPay Server
Installed btcpay-restart.sh to /usr/local/bin: Command line for restarting all services related to BTCPay Server
Installed btcpay-setup.sh to /usr/local/bin: Command line for restarting all services related to BTCPay Server
Installed btcpay-up.sh to /usr/local/bin: Command line for starting all services related to BTCPay Server
Installed btcpay-admin.sh to /usr/local/bin: Command line for some administrative operation in BTCPay Server
Installed btcpay-update.sh to /usr/local/bin: Command line for updating your BTCPay Server to the latest commit of this repository
Installed changedomain.sh to /usr/local/bin: Command line for changing the external domain of your BTCPay Server
@Giszmo
Copy link
Author

Giszmo commented Jun 2, 2021

So as I was able to send out some funds after the above issue, I sent some more funds there to see if I can get those back instantly. Now the issue is reproducible 100%.

Please correct me if my assumptions are wrong:

  • If I send 200ksat from my Phoenix wallet to my Spark wallet, I should be able to instantly send back 100ksat along the same route, if tiny amounts do work.
  • Ran out of routes to try after 28 attempts: see 'paystatus' means it could not find that route that worked before in the opposite direction? Does that mean that spark is missing topology information or is it more likely that nodes on the way favor one direction over the other? How can I see the used routes? I can't find it neither in Spark nor in Phoenix.

@Giszmo
Copy link
Author

Giszmo commented Jun 2, 2021

I see this is probably a btcpayserver issue after all. Or https://github.com/btcpayserver/btcpayserver-docker/pull/448/files to be precise. They are behind by two years.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant