search

RGB-Tools / rgb-lightning-node

MIT License
17 stars 19 forks source link

Locking/unlocking causes the node to crash #23

Closed gofman8 closed 5 months ago

gofman8 commented 6 months ago

Node running command: ./regtest.sh start && docker run -p 3001:3001 -ti --rm rln-node user:password@localhost:18443 /dataldk2/ --daemon-listening-port 3001 --ldk-peer-listening-port 9735 --network regtest

The following requests crashes the node:

curl -X 'POST'  'http://localhost:3001/init'   -H 'accept: application/json'   -H 'Content-Type: application/json'   -d '{ "password": "nodepassword" }'
curl -X 'POST'  'http://localhost:3001/unlock'   -H 'accept: application/json'   -H 'Content-Type: application/json'   -d '{ "password": "nodepassword" }'
curl -X 'POST'  'http://localhost:3001/lock'   
curl -X 'POST'  'http://localhost:3001/unlock'   -H 'accept: application/json'   -H 'Content-Type: application/json'   -d '{ "password": "nodepassword" }'

Node logs:

2024-03-12T16:30:03.919500Z INFO rgb_lightning_node: Listening on 0.0.0.0:3001 ^E2024-03-12T16:30:52.068131Z INFO rgb_lightning_node::utils: Created a new wallet 2024-03-12T16:30:52.069568Z INFO request{method=POST uri=/init version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=38 ms status=200 2024-03-12T16:31:05.111786Z INFO request{method=POST uri=/unlock version=HTTP/1.1}: rgb_lightning_node::routes: Unlock started 2024-03-12T16:31:05.690753Z INFO rgb::runtime: Stock file not found, creating default stock
2024-03-12T16:31:05.921158Z INFO rgb::runtime: Wallet file not found, creating new wallet list
2024-03-12T16:31:08.335434Z INFO sqlx::query: summary="PRAGMA foreign_keys = ON; …" db.statement="\n\nPRAGMA foreign_keys = ON;\n" rows_affected=0 rows_returned=0 elapsed=410.787µs 2024-03-12T16:31:08.347677Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"seaql_migrations\" (\n \"version\" text NOT NULL PRIMARY KEY,\n \"applied_at\" bigint NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=6.328754ms 2024-03-12T16:31:08.348604Z INFO sea_orm_migration::migrator: Applying all pending migrations 2024-03-12T16:31:08.350638Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"seaql_migrations\" (\n \"version\" text NOT NULL PRIMARY KEY,\n \"applied_at\" bigint NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=103.721µs 2024-03-12T16:31:08.352063Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"seaql_migrations\" (\n \"version\" text NOT NULL PRIMARY KEY,\n \"applied_at\" bigint NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=62.644µs 2024-03-12T16:31:08.353536Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"seaql_migrations\" (\n \"version\" text NOT NULL PRIMARY KEY,\n \"applied_at\" bigint NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=43.088µs 2024-03-12T16:31:08.357500Z INFO sqlx::query: summary="SELECT \"version\", \"applied_at\" FROM …" db.statement="\n\nSELECT\n \"version\",\n \"applied_at\"\nFROM\n \"seaql_migrations\"\nORDER BY\n \"version\" ASC\n" rows_affected=0 rows_returned=0 elapsed=461.497µs 2024-03-12T16:31:08.360862Z INFO sea_orm_migration::migrator: Applying migration 'm20230608_071249_init_db' 2024-03-12T16:31:08.366255Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"txo\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"txid\" text NOT NULL,\n \"vout\" bigint NOT NULL,\n \"btc_amount\" text NOT NULL,\n \"spent\" boolean NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=3.023939ms 2024-03-12T16:31:08.370887Z INFO sqlx::query: summary="CREATE UNIQUE INDEX \"idx-txo-txid-vout\" …" db.statement="\n\nCREATE UNIQUE INDEX \"idx-txo-txid-vout\" ON \"txo\" (\"txid\", \"vout\")\n" rows_affected=0 rows_returned=0 elapsed=2.354953ms 2024-03-12T16:31:08.374857Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"media\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"digest\" text NOT NULL UNIQUE,\n \"mime\" text NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=2.006615ms 2024-03-12T16:31:08.381608Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"asset\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"media_idx\" integer,\n \"asset_id\" text NOT NULL UNIQUE,\n \"schema\" integer NOT NULL,\n \"added_at\" bigint NOT NULL,\n \"details\" text,\n \"issued_supply\" text NOT NULL,\n \"name\" text NOT NULL,\n \"precision\" integer NOT NULL,\n \"ticker\" text,\n \"timestamp\" bigint NOT NULL,\n FOREIGN KEY (\"media_idx\") REFERENCES \"media\" (\"idx\") ON DELETE RESTRICT ON\n UPDATE\n CASCADE\n)\n" rows_affected=0 rows_returned=0 elapsed=2.281525ms 2024-03-12T16:31:08.387133Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"batch_transfer\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"txid\" text,\n \"status\" integer NOT NULL,\n \"created_at\" bigint NOT NULL,\n \"updated_at\" bigint NOT NULL,\n \"expiration\" bigint,\n \"min_confirmations\" integer NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=2.439026ms 2024-03-12T16:31:08.392830Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"asset_transfer\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"user_driven\" boolean NOT NULL,\n \"batch_transfer_idx\" integer NOT NULL,\n \"asset_id\" text,\n FOREIGN KEY (\"batch_transfer_idx\") REFERENCES \"batch_transfer\" (\"idx\") ON DELETE CASCADE ON\n UPDATE\n CASCADE,\n FOREIGN KEY (\"asset_id\") REFERENCES \"asset\" (\"asset_id\") ON DELETE CASCADE ON\n UPDATE\n CASCADE\n)\n" rows_affected=0 rows_returned=0 elapsed=2.197787ms 2024-03-12T16:31:08.399101Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"coloring\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"txo_idx\" integer NOT NULL,\n \"asset_transfer_idx\" integer NOT NULL,\n \"coloring_type\" integer NOT NULL,\n \"amount\" text NOT NULL,\n FOREIGN KEY (\"asset_transfer_idx\") REFERENCES \"asset_transfer\" (\"idx\") ON DELETE RESTRICT ON\n UPDATE\n RESTRICT,\n FOREIGN KEY (\"txo_idx\") REFERENCES \"txo\" (\"idx\") ON DELETE RESTRICT ON\n UPDATE\n RESTRICT\n)\n" rows_affected=0 rows_returned=0 elapsed=2.292729ms 2024-03-12T16:31:08.404162Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"transfer\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"asset_transfer_idx\" integer NOT NULL,\n \"amount\" text NOT NULL,\n \"incoming\" boolean NOT NULL,\n \"recipient_type\" integer,\n \"recipient_id\" text,\n \"ack\" boolean,\n \"vout\" bigint,\n FOREIGN KEY (\"asset_transfer_idx\") REFERENCES \"asset_transfer\" (\"idx\") ON DELETE CASCADE ON\n UPDATE\n CASCADE\n)\n" rows_affected=0 rows_returned=0 elapsed=1.995493ms 2024-03-12T16:31:08.410081Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"transport_endpoint\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"transport_type\" integer NOT NULL,\n \"endpoint\" text NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=3.255862ms 2024-03-12T16:31:08.414235Z INFO sqlx::query: summary="CREATE UNIQUE INDEX \"idx-transportendpoint-transporttype-endpoint\" …" db.statement="\n\nCREATE UNIQUE INDEX \"idx-transportendpoint-transporttype-endpoint\" ON \"transport_endpoint\" (\"transport_type\", \"endpoint\")\n" rows_affected=0 rows_returned=0 elapsed=2.434815ms 2024-03-12T16:31:08.421643Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"transfer_transport_endpoint\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"transfer_idx\" integer NOT NULL,\n \"transport_endpoint_idx\" integer NOT NULL,\n \"used\" boolean NOT NULL DEFAULT FALSE,\n FOREIGN KEY (\"transfer_idx\") REFERENCES \"transfer\" (\"idx\") ON DELETE CASCADE ON\n UPDATE\n CASCADE,\n FOREIGN KEY (\"transport_endpoint_idx\") REFERENCES \"transport_endpoint\" (\"idx\") ON DELETE RESTRICT ON\n UPDATE\n RESTRICT\n)\n" rows_affected=0 rows_returned=0 elapsed=2.265178ms 2024-03-12T16:31:08.427560Z INFO sqlx::query: summary="CREATE UNIQUE INDEX \"idx-tte-transferidx-transportendpointidx\" …" db.statement="\n\nCREATE UNIQUE INDEX \"idx-tte-transferidx-transportendpointidx\" ON \"transfer_transport_endpoint\" (\"transfer_idx\", \"transport_endpoint_idx\")\n" rows_affected=0 rows_returned=0 elapsed=3.911645ms 2024-03-12T16:31:08.436053Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"token\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"asset_idx\" integer NOT NULL,\n \"index\" bigint NOT NULL,\n \"ticker\" text,\n \"name\" text,\n \"details\" text,\n \"embedded_media\" boolean NOT NULL,\n \"reserves\" boolean NOT NULL,\n FOREIGN KEY (\"asset_idx\") REFERENCES \"asset\" (\"idx\") ON DELETE CASCADE ON\n UPDATE\n CASCADE\n)\n" rows_affected=0 rows_returned=0 elapsed=3.628025ms 2024-03-12T16:31:08.441926Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"token_media\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"token_idx\" integer NOT NULL,\n \"media_idx\" integer NOT NULL,\n \"attachment_id\" integer,\n FOREIGN KEY (\"token_idx\") REFERENCES \"token\" (\"idx\") ON DELETE CASCADE ON\n UPDATE\n CASCADE,\n FOREIGN KEY (\"media_idx\") REFERENCES \"media\" (\"idx\") ON DELETE RESTRICT ON\n UPDATE\n RESTRICT\n)\n" rows_affected=0 rows_returned=0 elapsed=2.258072ms 2024-03-12T16:31:08.446140Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"wallet_transaction\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"txid\" text NOT NULL,\n \"wallet_transaction_type\" integer NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=2.064723ms 2024-03-12T16:31:08.449368Z INFO sqlx::query: summary="CREATE UNIQUE INDEX \"idx-coloring-assettransferidx-txoidx\" …" db.statement="\n\nCREATE UNIQUE INDEX \"idx-coloring-assettransferidx-txoidx\" ON \"coloring\" (\"asset_transfer_idx\", \"txo_idx\")\n" rows_affected=0 rows_returned=0 elapsed=1.942911ms 2024-03-12T16:31:08.453099Z INFO sqlx::query: summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS \"backup_info\" (\n \"idx\" integer NOT NULL PRIMARY KEY AUTOINCREMENT,\n \"last_backup_timestamp\" text NOT NULL,\n \"last_operation_timestamp\" text NOT NULL\n)\n" rows_affected=0 rows_returned=0 elapsed=1.860702ms 2024-03-12T16:31:08.453583Z INFO sea_orm_migration::migrator: Migration 'm20230608_071249_init_db' has been applied 2024-03-12T16:31:08.460474Z INFO sqlx::query: summary="INSERT INTO \"seaql_migrations\" (\"version\", …" db.statement="\n\nINSERT INTO\n \"seaql_migrations\" (\"version\", \"applied_at\")\nVALUES\n (?, ?)\n" rows_affected=1 rows_returned=0 elapsed=2.726118ms 2024-03-12T16:31:08.710507Z INFO electrum_client::raw_client: Trying to connect to 18.119.98.232:50001 (attempt 1/1) with timeout 4s
2024-03-12T16:31:08.842386Z INFO electrum_client::raw_client: Trying to connect to 18.119.98.232:50001 (attempt 1/1) with timeout 5s
2024-03-12T16:31:09.341456Z INFO bdk::wallet: Derivation of 100 addresses from 0 took 64 ms
2024-03-12T16:31:09.404752Z INFO bdk::wallet: Derivation of 100 addresses from 0 took 58 ms
2024-03-12T16:31:13.928405Z INFO bdk::blockchain::script_sync: finished setup, elapsed 4517ms
2024-03-12T16:31:14.071194Z INFO sqlx::query: summary="SELECT \"txo\".\"idx\", \"txo\".\"txid\", \"txo\".\"vout\", …" db.statement="\n\nSELECT\n \"txo\".\"idx\",\n \"txo\".\"txid\",\n \"txo\".\"vout\",\n \"txo\".\"btc_amount\",\n \"txo\".\"spent\"\nFROM\n \"txo\"\n" rows_affected=1 rows_returned=0 elapsed=467.771µs 2024-03-12T16:31:14.074537Z INFO sqlx::query: summary="SELECT \"txo\".\"idx\", \"txo\".\"txid\", \"txo\".\"vout\", …" db.statement="\n\nSELECT\n \"txo\".\"idx\",\n \"txo\".\"txid\",\n \"txo\".\"vout\",\n \"txo\".\"btc_amount\",\n \"txo\".\"spent\"\nFROM\n \"txo\"\n" rows_affected=1 rows_returned=0 elapsed=56.245µs 2024-03-12T16:31:14.078612Z INFO sqlx::query: summary="SELECT \"asset\".\"idx\", \"asset\".\"media_idx\", \"asset\".\"asset_id\", …" db.statement="\n\nSELECT\n \"asset\".\"idx\",\n \"asset\".\"media_idx\",\n \"asset\".\"asset_id\",\n \"asset\".\"schema\",\n \"asset\".\"added_at\",\n \"asset\".\"details\",\n \"asset\".\"issued_supply\",\n \"asset\".\"name\",\n \"asset\".\"precision\",\n \"asset\".\"ticker\",\n \"asset\".\"timestamp\"\nFROM\n \"asset\"\n" rows_affected=1 rows_returned=0 elapsed=182.017µs 2024-03-12T16:31:14.080611Z INFO sqlx::query: summary="SELECT \"media\".\"idx\", \"media\".\"digest\", \"media\".\"mime\" …" db.statement="\n\nSELECT\n \"media\".\"idx\",\n \"media\".\"digest\",\n \"media\".\"mime\"\nFROM\n \"media\"\n" rows_affected=1 rows_returned=0 elapsed=137.118µs 2024-03-12T16:31:14.281366Z INFO rgb_lightning_node::ldk: LDK logs are available at /.ldk/logs 2024-03-12T16:31:14.281867Z INFO rgb_lightning_node::ldk: Local Node ID is 03b96550ee075ac940478e82c2c0af03e112f903a86d6206ac167bbf5b2b129541 2024-03-12T16:31:14.282274Z INFO rgb_lightning_node::routes: Unlock completed 2024-03-12T16:31:14.284142Z INFO request{method=POST uri=/unlock version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=9172 ms status=200 2024-03-12T16:32:18.623507Z INFO request{method=GET uri=/unlock version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=405 2024-03-12T16:32:26.398812Z INFO request{method=GET uri=/nodeinfo version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=200 2024-03-12T16:32:41.592280Z INFO request{method=POST uri=/lock version=HTTP/1.1}: rgb_lightning_node::routes: Lock started 2024-03-12T16:32:41.593008Z INFO rgb_lightning_node::ldk: Stopping LDK 2024-03-12T16:32:41.599846Z INFO rgb_lightning_node::ldk: Stopped LDK 2024-03-12T16:32:41.600156Z INFO rgb_lightning_node::routes: Lock completed 2024-03-12T16:32:41.600384Z INFO request{method=POST uri=/lock version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=8 ms status=200 2024-03-12T16:32:48.043092Z INFO request{method=GET uri=/nodeinfo version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=403 2024-03-12T16:32:54.369534Z INFO request{method=GET uri=/unlock version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=0 ms status=405 2024-03-12T16:33:01.915505Z INFO request{method=POST uri=/unlock version=HTTP/1.1}: rgb_lightning_node::routes: Unlock started thread 'tokio-runtime-worker' panicked at src/ldk.rs:1443:14: Failed to bind to listen port - is something else already listening on it?: Os { code: 98, kind: AddrInUse, message: "Address already in use" } note: run with RUST_BACKTRACE=1 environment variable to display a backtrace thread 'tokio-runtime-worker' panicked at src/ldk.rs:1498:10: valid rgb-lib wallet: Internal { details: "Error from bdk: Sled database error: IO error: could not acquire lock on \"/dataldk2/7e92a7c9/bdk_db/db\": Os { code: 11, kind: WouldBlock, message: \"Resource temporarily unavailable\" }" } thread 'tokio-runtime-worker' panicked at src/ldk.rs:1501:6: called Result::unwrap() on an Err value: JoinError::Panic(Id(25), ...) thread 'tokio-runtime-worker' panicked at src/utils.rs:284:14: called Result::unwrap() on an Err value: RecvError(())

nicbus commented 6 months ago

Thanks for reporting this. The issue has been addressed in the master branch.

Can you please confirm it's solved for you?

gofman8 commented 6 months ago

Thanks for reporting this. The issue has been addressed in the master branch.

Can you please confirm it's solved for you?

Thank you for extremely fast update! I will back to you with results

gofman8 commented 5 months ago

@nicbus Issue fully resolved, thanks you!