ExchangeUnion / xud

Exchange Union Daemon 🔁 ⚡️
https://exchangeunion.com
GNU Affero General Public License v3.0
115 stars 49 forks source link

EVP_DecryptFinal_ex:bad decrypt err after unlocking (may be connected with password change) #2047

Open raladev opened 3 years ago

raladev commented 3 years ago

Got this error today after unlocking my current simnet env, yesturday i tested password change endpoint, so err may be connected with it.

There is no reliable steps for now, because im sure that i was able to unlock xud after password change yesterday, will try to find the steps. This issue is created for not forgetting this err. P1 prio because passchange functionality is must have for windows desktop setup.

roma@roma-ThinkPad-X1-Carbon-6th:~/.xud-docker$ bash xud.sh -b pr
1) Simnet
2) Testnet
3) Mainnet
Please choose the network: 1
Pulling image exchangeunion/utils:latest
Warning: Branch image exchangeunion/utils:latest__pr not found. Fallback to exchangeunion/utils:latest
🚀 Launching simnet environment
🌍 Checking for updates...
- Container simnet_connext_1: recreate
A new version is available. Would you like to upgrade (Warning: this may restart your environment and cancel all open orders)? [Y/n] Y
Recreating simnet_connext_1...

🏃 Warming up...

Enter master xud password: 
Error: 2 UNKNOWN: error:06065064:digital envelope routines:EVP_DecryptFinal_ex:bad decrypt

Enter master xud password: 
xud is running and unlocked, try checking its status with 'xucli getinfo'

Enter master xud password: 
                           .___           __  .__   
          ___  _____ __  __| _/     _____/  |_|  |  
          \  \/  /  |  \/ __ |    _/ ___\   __\  |  
           >    <|  |  / /_/ |    \  \___|  | |  |__
          /__/\_ \____/\____ |     \___  >__| |____/
                \/          \/         \/           
--------------------------------------------------------------

simnet > status
┌─────────┬──────────────────────────────────────────────────┐
│ SERVICE │ STATUS                                           │
├─────────┼──────────────────────────────────────────────────┤
│ lndbtc  │ Wallet locked. Unlock with xucli unlock.         │
├─────────┼──────────────────────────────────────────────────┤
│ lndltc  │ Wallet locked. Unlock with xucli unlock.         │
├─────────┼──────────────────────────────────────────────────┤
│ connext │ Ready                                            │
├─────────┼──────────────────────────────────────────────────┤
│ proxy   │ Ready                                            │
├─────────┼──────────────────────────────────────────────────┤
│ xud     │ Ready                                            │
└─────────┴──────────────────────────────────────────────────┘
simnet > getbalance

Balance:
┌──────────┬───────────────┬───────────────────────────────┬────────────────────────────┐
│ Currency │ Total Balance │ Wallet Balance (Not Tradable) │ Channel Balance (Tradable) │
└──────────┴───────────────┴───────────────────────────────┴────────────────────────────┘
simnet > 
Dec 22 14:21:32.000 [notice] Parsing GEOIP IPv6 file /usr/share/tor/geoip6.
Dec 22 14:21:32.000 [warn] You are running Tor as root. You don't need to, and you probably shouldn't.
Dec 22 14:21:32.000 [notice] Bootstrapped 0% (starting): Starting
22/12/2020 14:21:32.959 [BACKUP] verbose: Writing initial xud database backup to: /mnt/hostfs/home/roma/.xud-docker/simnet/xud
22/12/2020 14:21:32.967 [BACKUP] verbose: Listening for changes to the xud database
22/12/2020 14:21:32.968 [BACKUP] info: Started backup daemon
22/12/2020 14:21:32.987 [BACKUP] info: Waiting for lnd-BTC
22/12/2020 14:21:32.988 [BACKUP] info: Waiting for lnd-LTC
Dec 22 14:21:33.000 [notice] Starting with guard context "default"
22/12/2020 14:21:33.685 [GLOBAL] info: config file loaded
22/12/2020 14:21:33.695 [RPC] info: gRPC server listening on 0.0.0.0:28886
22/12/2020 14:21:33.843 [DB] info: connected to database /root/.xud/xud-simnet.db
22/12/2020 14:21:33.873 [LND-BTC] debug: loaded tls cert from /root/.lndbtc/tls.cert
22/12/2020 14:21:33.875 [LND-LTC] debug: loaded tls cert from /root/.lndltc/tls.cert
22/12/2020 14:21:33.876 [LND-BTC] debug: loaded macaroon from /root/.lndbtc/data/chain/bitcoin/simnet/admin.macaroon
22/12/2020 14:21:33.876 [LND-BTC] info: new status: Initialized
22/12/2020 14:21:33.878 [LND-BTC] info: trying to verify connection to lnd at lndbtc:10009
22/12/2020 14:21:33.880 [LND-LTC] debug: loaded macaroon from /root/.lndltc/data/chain/litecoin/simnet/admin.macaroon
22/12/2020 14:21:33.880 [LND-LTC] info: new status: Initialized
22/12/2020 14:21:33.880 [LND-LTC] info: trying to verify connection to lnd at lndltc:10009
22/12/2020 14:21:33.888 [LND-BTC] info: new status: WaitingUnlock
22/12/2020 14:21:33.888 [LND-BTC] error: could not verify connection at lndbtc:10009, error: {"code":12,"metadata":{"_internal_repr":{},"flags":0},"details":"unknown service lnrpc.Lightning"}, retrying in 5000 ms
22/12/2020 14:21:33.889 [LND-LTC] info: new status: WaitingUnlock
22/12/2020 14:21:33.890 [LND-LTC] error: could not verify connection at lndltc:10009, error: {"code":12,"metadata":{"_internal_repr":{},"flags":0},"details":"unknown service lnrpc.Lightning"}, retrying in 5000 ms
22/12/2020 14:21:33.890 [GLOBAL] info: Node key is encrypted, unlock with 'xucli unlock', 'xucli create', or 'xucli restore'
Dec 22 14:21:34.000 [notice] Bootstrapped 5% (conn): Connecting to a relay
Dec 22 14:21:34.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay
Dec 22 14:21:34.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
Dec 22 14:21:34.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
Dec 22 14:21:34.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
Dec 22 14:21:34.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
Dec 22 14:21:34.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
Dec 22 14:21:35.000 [notice] Bootstrapped 100% (done): Done
22/12/2020 14:21:36.408 [RPC] error: call /xudrpc.Xud/GetInfo errored with code 12: xud is locked
22/12/2020 14:21:37.485 [RPC] error: call /xudrpc.Xud/GetInfo errored with code 12: xud is locked
22/12/2020 14:21:42.246 [GLOBAL] info: Local nodePubKey is 0341c1e4b228748534d5363bad1af17174cfedc2880175aea1f504c9744a3f8b6c
22/12/2020 14:21:42.286 [RPC] error: call /xudrpc.XudInit/UnlockNode errored with code 2: error:06065064:digital envelope routines:EVP_DecryptFinal_ex:bad decrypt
22/12/2020 14:21:42.290 [P2P] info: Connecting to simnet XU network
22/12/2020 14:21:42.293 [P2P] info: p2p server listening on 0.0.0.0:28885
22/12/2020 14:21:42.295 [P2P] debug: Verifying reachability of advertised address: muesyub65icakhtmz4tynbfchjhaxih7rb3ncdmvn6djcc6jkmufhcyd.onion:28885
22/12/2020 14:21:42.313 [P2P] info: Connecting to known / previously connected peers
22/12/2020 14:21:42.315 [P2P] debug: creating new outbound socket connection to xud1.simnet.exchangeunion.com:28885
22/12/2020 14:21:42.316 [P2P] debug: creating new outbound socket connection to ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885
22/12/2020 14:21:42.317 [P2P] debug: creating new outbound socket connection to ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885
22/12/2020 14:21:42.318 [P2P] debug: creating new outbound socket connection to 45yk255qoorqjcf672spyalyiymxikxxfv2eqovhhpy7ofagetvvenid.onion:28885
22/12/2020 14:21:42.319 [P2P] debug: creating new outbound socket connection to ifcuhhnt43ls75rujgvj7msiujc76l6dni2l4gqlt3atut75hncqwlid.onion:28885
22/12/2020 14:21:42.320 [P2P] debug: creating new outbound socket connection to wx4cqdap3tl3rukivzyvqwfc2loszwjilikpd5ot5mk3nj767d2nhuyd.onion:28885
22/12/2020 14:21:42.581 [P2P] debug: Connected pre-handshake to 03ece33a30db1dbce4b62fa96a5e9541138a24997ef5672eebed2d332270e39542@xud1.simnet.exchangeunion.com:28885
22/12/2020 14:21:42.730 [P2P] debug: Peer 03ece33a30db1dbce4b62fa96a5e9541138a24997ef5672eebed2d332270e39542@xud1.simnet.exchangeunion.com:28885 session in-encryption enabled
22/12/2020 14:21:42.792 [P2P] debug: Peer 03ece33a30db1dbce4b62fa96a5e9541138a24997ef5672eebed2d332270e39542 (OzoneYellow) session out-encryption enabled
22/12/2020 14:21:42.793 [P2P] verbose: opened connection to 03ece33a30db1dbce4b62fa96a5e9541138a24997ef5672eebed2d332270e39542 (OzoneYellow) at xud1.simnet.exchangeunion.com:28885
22/12/2020 14:21:43.014 [P2P] verbose: received 1 nodes (0 new) from 03ece33a30db1dbce4b62fa96a5e9541138a24997ef5672eebed2d332270e39542 (OzoneYellow)
22/12/2020 14:21:43.014 [P2P] debug: creating new outbound socket connection to 45yk255qoorqjcf672spyalyiymxikxxfv2eqovhhpy7ofagetvvenid.onion:28885
22/12/2020 14:21:48.232 [P2P] debug: new inbound socket connection from 127.0.0.1:45946
22/12/2020 14:21:48.235 [P2P] debug: Connected pre-handshake to 127.0.0.1:45946
22/12/2020 14:21:48.572 [P2P] debug: Peer 0341c1e4b228748534d5363bad1af17174cfedc2880175aea1f504c9744a3f8b6c (HobbyFirst): closing socket. reason: ConnectedToSelf
22/12/2020 14:21:48.580 [P2P] warn: could not open connection to inbound peer (0341c1e4b228748534d5363bad1af17174cfedc2880175aea1f504c9744a3f8b6c (HobbyFirst)): cannot attempt connection to self
22/12/2020 14:21:48.730 [P2P] verbose: Verified reachability of advertised address: muesyub65icakhtmz4tynbfchjhaxih7rb3ncdmvn6djcc6jkmufhcyd.onion:28885
Dec 22 14:21:48.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:21:48.805 [P2P] warn: could not open connection to outbound peer (0229a275cfcc441bc6b8e424fdd087d93dd91c7dc1ecbd8735794366f2f82e220c@ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885): could not connect to peer at ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885: Socks5 proxy rejected connection - HostUnreachable
22/12/2020 14:21:48.806 [P2P] debug: creating new outbound socket connection to ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885
22/12/2020 14:21:49.175 [P2P] debug: Connected pre-handshake to 03155c49607cdcd5e278db3978bebc8853d3a66f777c0e8e32ac021fae5a3bb146@45yk255qoorqjcf672spyalyiymxikxxfv2eqovhhpy7ofagetvvenid.onion:28885
22/12/2020 14:21:49.488 [P2P] debug: Peer 03155c49607cdcd5e278db3978bebc8853d3a66f777c0e8e32ac021fae5a3bb146@45yk255qoorqjcf672spyalyiymxikxxfv2eqovhhpy7ofagetvvenid.onion:28885 session in-encryption enabled
22/12/2020 14:21:49.544 [P2P] debug: Peer 03155c49607cdcd5e278db3978bebc8853d3a66f777c0e8e32ac021fae5a3bb146 (CauseArctic) session out-encryption enabled
22/12/2020 14:21:49.545 [P2P] verbose: opened connection to 03155c49607cdcd5e278db3978bebc8853d3a66f777c0e8e32ac021fae5a3bb146 (CauseArctic) at 45yk255qoorqjcf672spyalyiymxikxxfv2eqovhhpy7ofagetvvenid.onion:28885
22/12/2020 14:21:49.884 [P2P] verbose: received 1 nodes (0 new) from 03155c49607cdcd5e278db3978bebc8853d3a66f777c0e8e32ac021fae5a3bb146 (CauseArctic)
Dec 22 14:21:51.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:21:51.312 [P2P] warn: could not open connection to outbound peer (03df4f36fa35bd242263e8d09d6b422108dab1f08d91237bb3aa2dad957cf08a71@ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885): could not connect to peer at ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885: Socks5 proxy rejected connection - HostUnreachable
22/12/2020 14:21:51.312 [P2P] debug: creating new outbound socket connection to ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885
Dec 22 14:21:52.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:21:52.335 [P2P] warn: could not open connection to outbound peer (03f86a342d0760406a88fd9cb4f168118ce3dc22bf27e5dc177ec6cf1e488e366c@wx4cqdap3tl3rukivzyvqwfc2loszwjilikpd5ot5mk3nj767d2nhuyd.onion:28885): could not connect to peer at wx4cqdap3tl3rukivzyvqwfc2loszwjilikpd5ot5mk3nj767d2nhuyd.onion:28885: Socks5 proxy rejected connection - HostUnreachable
Dec 22 14:21:54.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:21:54.002 [P2P] warn: could not open connection to outbound peer (03c4a11fdfe257771cdd188064749f59f6b4ffd9708b93c22d365cdb0dffb588eb@ifcuhhnt43ls75rujgvj7msiujc76l6dni2l4gqlt3atut75hncqwlid.onion:28885): could not connect to peer at ifcuhhnt43ls75rujgvj7msiujc76l6dni2l4gqlt3atut75hncqwlid.onion:28885: Socks5 proxy rejected connection - HostUnreachable
22/12/2020 14:21:58.616 [RPC] error: call /xudrpc.XudInit/UnlockNode errored with code 12: xud init service is disabled
Dec 22 14:21:58.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:21:58.914 [P2P] debug: Connection attempt #1 to 0229a275cfcc441bc6b8e424fdd087d93dd91c7dc1ecbd8735794366f2f82e220c@ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 5 sec...
Dec 22 14:22:00.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:22:00.042 [P2P] debug: Connection attempt #1 to 03df4f36fa35bd242263e8d09d6b422108dab1f08d91237bb3aa2dad957cf08a71@ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 5 sec...
Dec 22 14:22:10.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:22:10.526 [P2P] debug: Connection attempt #2 to 0229a275cfcc441bc6b8e424fdd087d93dd91c7dc1ecbd8735794366f2f82e220c@ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 10 sec...
Dec 22 14:22:11.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:22:11.293 [P2P] debug: Connection attempt #2 to 03df4f36fa35bd242263e8d09d6b422108dab1f08d91237bb3aa2dad957cf08a71@ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 10 sec...
Dec 22 14:22:29.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:22:29.159 [P2P] debug: Connection attempt #3 to 0229a275cfcc441bc6b8e424fdd087d93dd91c7dc1ecbd8735794366f2f82e220c@ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 20 sec...
Dec 22 14:22:31.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:22:31.541 [P2P] debug: Connection attempt #3 to 03df4f36fa35bd242263e8d09d6b422108dab1f08d91237bb3aa2dad957cf08a71@ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 20 sec...
22/12/2020 14:22:38.976 [LND-BTC] error: getinfo error: 4.2 - lnd-BTC is WaitingUnlock
22/12/2020 14:22:38.976 [LND-LTC] error: getinfo error: 4.2 - lnd-LTC is WaitingUnlock
22/12/2020 14:22:39.051 [LND-BTC] error: getinfo error: 4.2 - lnd-BTC is WaitingUnlock
22/12/2020 14:22:39.051 [LND-LTC] error: getinfo error: 4.2 - lnd-LTC is WaitingUnlock
Dec 22 14:22:56.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:22:56.954 [P2P] debug: Connection attempt #4 to 03df4f36fa35bd242263e8d09d6b422108dab1f08d91237bb3aa2dad957cf08a71@ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 40 sec...
Dec 22 14:23:04.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:23:04.889 [P2P] debug: Connection attempt #4 to 0229a275cfcc441bc6b8e424fdd087d93dd91c7dc1ecbd8735794366f2f82e220c@ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 40 sec...
Dec 22 14:23:41.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:23:41.334 [P2P] debug: Connection attempt #5 to 03df4f36fa35bd242263e8d09d6b422108dab1f08d91237bb3aa2dad957cf08a71@ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 80 sec...
Dec 22 14:23:55.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:23:55.205 [P2P] debug: Connection attempt #5 to 0229a275cfcc441bc6b8e424fdd087d93dd91c7dc1ecbd8735794366f2f82e220c@ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 80 sec...
Dec 22 14:25:09.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:25:09.330 [P2P] debug: Connection attempt #6 to 03df4f36fa35bd242263e8d09d6b422108dab1f08d91237bb3aa2dad957cf08a71@ri3khz45h25dzxh32z2r7f3s2fgque6f77zygtanldio3z3ps3b3s3id.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 160 sec...
Dec 22 14:25:20.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
22/12/2020 14:25:20.659 [P2P] debug: Connection attempt #6 to 0229a275cfcc441bc6b8e424fdd087d93dd91c7dc1ecbd8735794366f2f82e220c@ueujqmjn7euls2uk2kgdcfdkqms4rfnb55pdcmlgjw7txzafs4jr2jid.onion:28885 failed: Socks5 proxy rejected connection - HostUnreachable. retrying in 160 sec...
kilrau commented 3 years ago

Great find! Needs a reliable way to reproduce though, ping us when you figured out the steps :pray: