search

Blockstream / greenlight

Build apps using self-custodial lightning nodes in the cloud
https://blockstream.github.io/greenlight/getting-started/
MIT License
110 stars 28 forks source link

Withdraw results in `non-mandatory-script-verify-flag (Witness program hash mismatch). Unsent tx discarded` #348

Closed dangeross closed 6 months ago

dangeross commented 8 months ago

A user is reporting several failed attempts to withdraw funds after a force close. The failure always results in the error:

Error calling method Withdraw: RpcError{ code: Some(-1), message: \"Error broadcasting transaction: error-code: -26\\\\nerror message: \\\\nnon-mandatory-script-verify-flag (Witness program hash mismatch). Unsent tx discarded ...

after which the utxo's are marked reserved for a day or so. Once the utxo's are available again, the user repeats resulting in the same error. Node id for reference is: 02810d14934b1b41b52af4b6c118878a00e857cc4922442ea59e18b31906b09c67

A similar issue is also raised in https://github.com/Blockstream/green_android/issues/185 relating to the same circumstances and error.

I have requested the user provides a trace log the next time they attempt a withdraw and will attach them to this issue.

dangeross commented 8 months ago

Here are the logs, the process starts at 2024-01-10T07:39:33.750Z and ends at 2024-01-10T07:39:36.591Z com.satimoto-latest.txt

ksedgwic commented 8 months ago

Here is a decode of the tx w/ the Witness program hash mismatch:

bitcoin-cli decoderawtransaction 020000000001013db0eb77d3275977ab5e33adbb35361c40eb8971db957491a73c53727ab2b5e3030000000001000000023e3704000000000016001487e09361881dcb6897e3161ee602f62290ba8d812202000000000000225120c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b02483045022100eba3c7db03e7be73a932d39816f10be376a79fb3ac2b960617a3331c5212ef0802201aaee301beac012ccd413a3ea6dbcd8edbf1ae3c26ccfc2ab979e70c352fc19b0121020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f33313970c00
{
  "txid": "c61a315065ffb927e5464515e632c24c617f126a556afccae3cf890aaa338e53",
  "hash": "e36191ca8f6f2313f50325e1e3a554fd6432f2a2e0dbcb941fe9b4ad283d3100",
  "version": 2,
  "size": 235,
  "vsize": 153,
  "weight": 610,
  "locktime": 825107,
  "vin": [
    {
      "txid": "e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d",
      "vout": 3,
      "scriptSig": {
        "asm": "",
        "hex": ""
      },
      "txinwitness": [
        "3045022100eba3c7db03e7be73a932d39816f10be376a79fb3ac2b960617a3331c5212ef0802201aaee301beac012ccd413a3ea6dbcd8edbf1ae3c26ccfc2ab979e70c352fc19b01",
        "020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f333"
      ],
      "sequence": 1
    }
  ],
  "vout": [
    {
      "value": 0.00276286,
      "n": 0,
      "scriptPubKey": {
        "asm": "0 87e09361881dcb6897e3161ee602f62290ba8d81",
        "desc": "addr(bc1qslsfxcvgrh9k39lrzc0wvqhky2gt4rvpwxmeap)#5kjmxkdg",
        "hex": "001487e09361881dcb6897e3161ee602f62290ba8d81",
        "address": "bc1qslsfxcvgrh9k39lrzc0wvqhky2gt4rvpwxmeap",
        "type": "witness_v0_keyhash"
      }
    },
    {
      "value": 0.00000546,
      "n": 1,
      "scriptPubKey": {
        "asm": "1 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b",
        "desc": "rawtr(c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b)#nj32wcvg",
        "hex": "5120c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b",
        "address": "bc1pc7fu67whtzcy5068rvvztdw5rh3wkcfgn6tv65kx7xs7wumwy6ds35es75",
        "type": "witness_v1_taproot"
      }
    }
  ]
}
cdecker commented 8 months ago

@ksedgwic I'm not quite up to speed on the error that is being reported here. Could this somehow be related to our use of VLS, or is this related to the data we feed into VLS?

ksedgwic commented 8 months ago

Log Excerpt and Analysis

The SignWithdrawal Logging ``` 2024-01-10T07:39:35.930Z [DEBUG] BreezSDK: [DEBUG] SignWithdrawal(SignWithdrawal { utxos: Array([Utxo { txid: e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d, outnum: 3, amount: 282008, keyindex: 0, is_p2sh: false, script: 00200549ae6098a014f9a0ed7ada3f1f1341aa3bd73e41470530cfafee0cea401685, close_info: Some(CloseInfo { channel_id: 2, peer_id: 03232432128398d8cb31e67921ffd4d4cfb10b42dc72529a45dba6f105adfb83d4, commitment_point: None, is_anchors: true, csv: 1 }), is_in_coinbase: false }]), psbt: WithSize(StreamedPSBT { psbt: PartiallySignedTransaction { unsigned_tx: Transaction { version: 2, lock_time: PackedLockTime(825107), input: [TxIn { previous_output: OutPoint { txid: e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d, vout: 3 }, script_sig: Script(), sequence: Sequence(1), witness: Witness { content: [], witness_elements: 0, last: 0, second_to_last: 0 } }], output: [TxOut { value: 276286, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 87e09361881dcb6897e3161ee602f62290ba8d81) }, TxOut { value: 546, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b) }] }, version: 0, xpub: {}, proprietary: {}, unknown: {}, inputs: [Input { non_witness_utxo: None, witness_utxo: Some(TxOut { value: 282008, script_pubkey: Script(OP_0 OP_PUSHBYTES_32 0549ae6098a014f9a0ed7ada3f1f1341aa3bd73e41470530cfafee0cea401685) }), partial_sigs: {}, sighash_type: None, redeem_script: None, witness_script: None, bip32_derivation: {}, final_script_sig: None, final_script_witness: None, ripemd160_preimages: {}, sha256_preimages: {}, hash160_preimages: {}, hash256_preimages: {}, tap_key_sig: None, tap_script_sigs: {}, tap_scripts: {}, tap_key_origins: {}, tap_internal_key: None, tap_merkle_root: None, proprietary: {}, unknown: {} }], outputs: [Output { redeem_script: None, witness_script: None, bip32_derivation: {}, tap_internal_key: None, tap_tree: None, tap_key_origins: {}, proprietary: {ProprietaryKey { prefix: [108, 105, 103, 104, 116, 110, 105, 110, 103], subtype: 4, key: [] }: [0, 1]}, unknown: {} }, Output { redeem_script: None, witness_script: None, bip32_derivation: {}, tap_internal_key: None, tap_tree: None, tap_key_origins: {XOnlyPublicKey(d4b2368a126fd976c4ef9bc3800f62b10c47ec0bdb8f62ce97f3581be49af0f33c47e38e007440674c149fcfdd0fc3e91460b05c2319fbdf4f8507337bc1ce3c): ([], (5506e7e7, m/5))}, proprietary: {}, unknown: {} }] }, segwit_flags: [true] }) }) 2024-01-10T07:39:35.930Z [DEBUG] BreezSDK: [TRACE] poll_complete 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [DEBUG] SignWithdrawal psbt StreamedPSBT { psbt: PartiallySignedTransaction { unsigned_tx: Transaction { version: 2, lock_time: PackedLockTime( 825107, ), input: [ TxIn { previous_output: OutPoint { txid: e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d, vout: 3, }, script_sig: Script(), sequence: Sequence( 1, ), witness: Witness { content: [], witness_elements: 0, last: 0, second_to_last: 0, }, }, ], output: [ TxOut { value: 276286, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 87e09361881dcb6897e3161ee602f62290ba8d81), }, TxOut { value: 546, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b), }, ], }, version: 0, xpub: {}, proprietary: {}, unknown: {}, inputs: [ Input { non_witness_utxo: None, witness_utxo: Some( TxOut { value: 282008, script_pubkey: Script(OP_0 OP_PUSHBYTES_32 0549ae6098a014f9a0ed7ada3f1f1341aa3bd73e41470530cfafee0cea401685), }, ), partial_sigs: {}, sighash_type: None, redeem_script: None, witness_script: None, bip32_derivation: {}, final_script_sig: None, final_script_witness: None, ripemd160_preimages: {}, sha256_preimages: {}, hash160_preimages: {}, hash256_preimages: {}, tap_key_sig: None, tap_script_sigs: {}, tap_scripts: {}, tap_key_origins: {}, tap_internal_key: None, tap_merkle_root: None, proprietary: {}, unknown: {}, }, ], outputs: [ Output { redeem_script: None, witness_script: None, bip32_derivation: {}, tap_internal_key: None, tap_tree: None, tap_key_origins: {}, proprietary: { ProprietaryKey { prefix: [ 108, 105, 103, 104, 116, 110, 105, 110, 103, ], subtype: 4, key: [], }: [ 0, 1, ], }, unknown: {}, }, Output { redeem_script: None, witness_script: None, bip32_derivation: {}, tap_internal_key: None, tap_tree: None, tap_key_origins: { XOnlyPublicKey( d4b2368a126fd976c4ef9bc3800f62b10c47ec0bdb8f62ce97f3581be49af0f33c47e38e007440674c149fcfdd0fc3e91460b05c2319fbdf4f8507337bc1ce3c, ): ( [], ( 5506e7e7, m/5, ), ), }, proprietary: {}, unknown: {}, }, ], }, segwit_flags: [ true, ], } 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [TRACE] schedule_pending_open 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [TRACE] pop_frame; 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [DEBUG] "ipaths": [ [ 0, ], ] 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [TRACE] -> pop_frame; 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [DEBUG] "opaths": [ [], [ 5, ], ] 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [TRACE] <- pop_frame; 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [DEBUG] "tx.txid()": c61a315065ffb927e5464515e632c24c617f126a556afccae3cf890aaa338e53 2024-01-10T07:39:35.931Z [DEBUG] BreezSDK: [TRACE] -- pop_frame; 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [TRACE] FramedWrite::flush; 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [DEBUG] "tx": Transaction { version: 2, lock_time: PackedLockTime( 825107, ), input: [ TxIn { previous_output: OutPoint { txid: e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d, vout: 3, }, script_sig: Script(), sequence: Sequence( 1, ), witness: Witness { content: [], witness_elements: 0, last: 0, second_to_last: 0, }, }, ], output: [ TxOut { value: 276286, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 87e09361881dcb6897e3161ee602f62290ba8d81), }, TxOut { value: 546, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b), }, ], } 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [TRACE] -> FramedWrite::flush; 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [DEBUG] "streamed.segwit_flags": [ true, ] 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [TRACE] flushing buffer 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [TRACE] <- FramedWrite::flush; 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [DEBUG] "uniclosekeys": [ Some( ( SecretKey( #020d039934d80918, ), [ [ 2, 13, 15, 97, 66, 198, 173, 124, 25, 8, 117, 131, 143, 122, 87, 188, 253, 204, 235, 110, 123, 204, 37, 56, 73, 208, 56, 168, 230, 216, 71, 243, 51, ], ], ), ), ] 2024-01-10T07:39:35.932Z [DEBUG] BreezSDK: [TRACE] -- FramedWrite::flush; 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [TRACE] try_reclaim_frame; 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [TRACE] -> try_reclaim_frame; 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [DEBUG] check_onchain_tx: txid: c61a315065ffb927e5464515e632c24c617f126a556afccae3cf890aaa338e53 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [TRACE] <- try_reclaim_frame; 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [DEBUG] weight_lower_bound: 611 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [TRACE] -- try_reclaim_frame; 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [TRACE] <- poll; 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [DEBUG] output 0 (276286) is unknown 2024-01-10T07:39:35.933Z [DEBUG] BreezSDK: [TRACE] -- poll; 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [TRACE] <- Connection; 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [TRACE] -- Connection; 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [TRACE] release_capacity; size=101 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [DEBUG] output 1 (546) is to our wallet 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [TRACE] release_connection_capacity; size=101, connection in_flight_data=324 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [DEBUG] node-logs: DEBUG plugin-gl-plugin-internal: Sending signer requests with 1 requests and 6 state entries 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [TRACE] release_capacity; size=123 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [TRACE] release_connection_capacity; size=123, connection in_flight_data=223 2024-01-10T07:39:35.934Z [DEBUG] BreezSDK: [DEBUG] node-logs: DEBUG plugin-gl-plugin-internal: Received event Ok(RpcCall(\"/greenlight.Node/RespondHsmRequest\")) from gl_plugin 2024-01-10T07:39:35.935Z [DEBUG] BreezSDK: [TRACE] release_capacity; size=100 2024-01-10T07:39:35.935Z [DEBUG] BreezSDK: [TRACE] release_connection_capacity; size=100, connection in_flight_data=100 2024-01-10T07:39:35.935Z [DEBUG] BreezSDK: [DEBUG] node-logs: DEBUG plugin-gl-plugin-internal: Response for request_id=1024, outstanding requests count=0 2024-01-10T07:39:35.937Z [DEBUG] BreezSDK: [DEBUG] validate_onchain_tx failed: 2024-01-10T07:39:35.937Z [DEBUG] BreezSDK: [DEBUG] "tx": Transaction { version: 2, lock_time: PackedLockTime( 825107, ), input: [ TxIn { previous_output: OutPoint { txid: e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d, vout: 3, }, script_sig: Script(), sequence: Sequence( 1, ), witness: Witness { content: [], witness_elements: 0, last: 0, second_to_last: 0, }, }, ], output: [ TxOut { value: 276286, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 87e09361881dcb6897e3161ee602f62290ba8d81), }, TxOut { value: 546, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b), }, ], } 2024-01-10T07:39:35.938Z [DEBUG] BreezSDK: [DEBUG] "values_sat": [ 282008, ] 2024-01-10T07:39:35.938Z [DEBUG] BreezSDK: [DEBUG] "opaths": [ [], [ 5, ], ] 2024-01-10T07:39:35.938Z [DEBUG] BreezSDK: [WARN] unapproved onchain Transaction { version: 2, lock_time: PackedLockTime(825107), input: [TxIn { previous_output: OutPoint { txid: e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d, vout: 3 }, script_sig: Script(), sequence: Sequence(1), witness: Witness { content: [], witness_elements: 0, last: 0, second_to_last: 0 } }], output: [TxOut { value: 276286, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 87e09361881dcb6897e3161ee602f62290ba8d81) }, TxOut { value: 546, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b) }] } [TxOut { value: 282008, script_pubkey: Script(OP_0 OP_PUSHBYTES_32 0549ae6098a014f9a0ed7ada3f1f1341aa3bd73e41470530cfafee0cea401685) }] [0] 2024-01-10T07:39:35.938Z [DEBUG] BreezSDK: [INFO] approved onchain tx with unknown outputs 2024-01-10T07:39:35.939Z [DEBUG] BreezSDK: [DEBUG] unchecked_sign_onchain_tx: txid: c61a315065ffb927e5464515e632c24c617f126a556afccae3cf890aaa338e53 2024-01-10T07:39:35.939Z [DEBUG] BreezSDK: [DEBUG] SignWithdrawalReply { psbt: WithSize(PartiallySignedTransaction { unsigned_tx: Transaction { version: 2, lock_time: PackedLockTime(825107), input: [TxIn { previous_output: OutPoint { txid: e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d, vout: 3 }, script_sig: Script(), sequence: Sequence(1), witness: Witness { content: [], witness_elements: 0, last: 0, second_to_last: 0 } }], output: [TxOut { value: 276286, script_pubkey: Script(OP_0 OP_PUSHBYTES_20 87e09361881dcb6897e3161ee602f62290ba8d81) }, TxOut { value: 546, script_pubkey: Script(OP_PUSHNUM_1 OP_PUSHBYTES_32 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b) }] }, version: 0, xpub: {}, proprietary: {}, unknown: {}, inputs: [Input { non_witness_utxo: None, witness_utxo: Some(TxOut { value: 282008, script_pubkey: Script(OP_0 OP_PUSHBYTES_32 0549ae6098a014f9a0ed7ada3f1f1341aa3bd73e41470530cfafee0cea401685) }), partial_sigs: {}, sighash_type: None, redeem_script: None, witness_script: None, bip32_derivation: {}, final_script_sig: None, final_script_witness: Some(Witness { content: [72, 48, 69, 2, 33, 0, 235, 163, 199, 219, 3, 231, 190, 115, 169, 50, 211, 152, 22, 241, 11, 227, 118, 167, 159, 179, 172, 43, 150, 6, 23, 163, 51, 28, 82, 18, 239, 8, 2, 32, 26, 174, 227, 1, 190, 172, 1, 44, 205, 65, 58, 62, 166, 219, 205, 142, 219, 241, 174, 60, 38, 204, 252, 42, 185, 121, 231, 12, 53, 47, 193, 155, 1, 33, 2, 13, 15, 97, 66, 198, 173, 124, 25, 8, 117, 131, 143, 122, 87, 188, 253, 204, 235, 110, 123, 204, 37, 56, 73, 208, 56, 168, 230, 216, 71, 243, 51], witness_elements: 2, last: 73, second_to_last: 0 }), ripemd160_preimages: {}, sha256_preimages: {}, hash160_preimages: {}, hash256_preimages: {}, tap_key_sig: None, tap_script_sigs: {}, tap_scripts: {}, tap_key_origins: {}, tap_internal_key: None, tap_merkle_root: None, proprietary: {}, unknown: {} }], outputs: [Output { redeem_script: None, witness_script: None, bip32_derivation: {}, tap_internal_key: None, tap_tree: None, tap_key_origins: {}, proprietary: {ProprietaryKey { prefix: [108, 105, 103, 104, 116, 110, 105, 110, 103], subtype: 4, key: [] }: [0, 1]}, unknown: {} }, Output { redeem_script: None, witness_script: None, bip32_derivation: {}, tap_internal_key: None, tap_tree: None, tap_key_origins: {XOnlyPublicKey(d4b2368a126fd976c4ef9bc3800f62b10c47ec0bdb8f62ce97f3581be49af0f33c47e38e007440674c149fcfdd0fc3e91460b05c2319fbdf4f8507337bc1ce3c): ([], (5506e7e7, m/5))}, proprietary: {}, unknown: {} }] }) } 2024-01-10T07:39:35.940Z [DEBUG] BreezSDK: [DEBUG] Serializing state changes to report to node 2024-01-10T07:39:35.941Z [DEBUG] BreezSDK: [TRACE] Sending response 006b0000016270736274ff01007d02000000013db0eb77d3275977ab5e33adbb35361c40eb8971db957491a73c53727ab2b5e3030000000001000000023e3704000000000016001487e09361881dcb6897e3161ee602f62290ba8d812202000000000000225120c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b13970c000001012b984d0400000000002200200549ae6098a014f9a0ed7ada3f1f1341aa3bd73e41470530cfafee0cea40168501086c02483045022100eba3c7db03e7be73a932d39816f10be376a79fb3ac2b960617a3331c5212ef0802201aaee301beac012ccd413a3ea6dbcd8edbf1ae3c26ccfc2ab979e70c352fc19b0121020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f333000cfc096c696768746e696e6704020001002107f3f09ae41b58f397ce628fdb0bec470cb1620f80c39befc476d96f128a36b2d409005506e7e70500000000 ```

The sendrawtx error:

2024-01-10T07:39:36.591Z [DEBUG]  BreezSDK: [DEBUG] node-logs: DEBUG   plugin-bcli: sendrawtx exit 26 (bitcoin-cli -rpcconnect=127.0.0.1 -rpcport=8332 -rpcuser=... -stdinrpcpass sendrawtransaction 020000000001013db0eb77d3275977ab5e33adbb35361c40eb8971db957491a73c53727ab2b5e3030000000001000000023e3704000000000016001487e09361881dcb6897e3161ee602f62290ba8d812202000000000000225120c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b02483045022100eba3c7db03e7be73a932d39816f10be376a79fb3ac2b960617a3331c5212ef0802201aaee301beac012ccd413a3ea6dbcd8edbf1ae3c26ccfc2ab979e70c352fc19b0121020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f33313970c00) error code: -26\nerror message:\nnon-mandatory-script-verify-flag (Witness program hash mismatch)

Parent tx in block explorer: https://mempool.space/tx/e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d

The transaction decoded:

bitcoin@home5:~$ bitcoin-cli decoderawtransaction 020000000001013db0eb77d3275977ab5e33adbb35361c40eb8971db957491a73c53727ab2b5e3030000000001000000023e3704000000000016001487e09361881dcb6897e3161ee602f62290ba8d812202000000000000225120c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b02483045022100eba3c7db03e7be73a932d39816f10be376a79fb3ac2b960617a3331c5212ef0802201aaee301beac012ccd413a3ea6dbcd8edbf1ae3c26ccfc2ab979e70c352fc19b0121020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f33313970c00
{
  "txid": "c61a315065ffb927e5464515e632c24c617f126a556afccae3cf890aaa338e53",
  "hash": "e36191ca8f6f2313f50325e1e3a554fd6432f2a2e0dbcb941fe9b4ad283d3100",
  "version": 2,
  "size": 235,
  "vsize": 153,
  "weight": 610,
  "locktime": 825107,
  "vin": [
    {
      "txid": "e3b5b27a72533ca7917495db7189eb401c3635bbad335eab775927d377ebb03d",
      "vout": 3,
      "scriptSig": {
        "asm": "",
        "hex": ""
      },
      "txinwitness": [
        "3045022100eba3c7db03e7be73a932d39816f10be376a79fb3ac2b960617a3331c5212ef0802201aaee301beac012ccd413a3ea6dbcd8edbf1ae3c26ccfc2ab979e70c352fc19b01",
        "020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f333"
      ],
      "sequence": 1
    }
  ],
  "vout": [
    {
      "value": 0.00276286,
      "n": 0,
      "scriptPubKey": {
        "asm": "0 87e09361881dcb6897e3161ee602f62290ba8d81",
        "desc": "addr(bc1qslsfxcvgrh9k39lrzc0wvqhky2gt4rvpwxmeap)#5kjmxkdg",
        "hex": "001487e09361881dcb6897e3161ee602f62290ba8d81",
        "address": "bc1qslsfxcvgrh9k39lrzc0wvqhky2gt4rvpwxmeap",
        "type": "witness_v0_keyhash"
      }
    },
    {
      "value": 0.00000546,
      "n": 1,
      "scriptPubKey": {
        "asm": "1 c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b",
        "desc": "rawtr(c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b)#nj32wcvg",
        "hex": "5120c793cd79d758b04a3f471b1825b5d41de2eb61289e96cd52c6f1a1e7736e269b",
        "address": "bc1pc7fu67whtzcy5068rvvztdw5rh3wkcfgn6tv65kx7xs7wumwy6ds35es75",
        "type": "witness_v1_taproot"
      }
    }
  ]
}

The witness script decoded:

bitcoin@home5:~$ bitcoin-cli decodescript 020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f333
{
  "asm": "3853 OP_NOP [error]",
  "desc": "raw(020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f333)#j7hk5lw4",
  "type": "nonstandard"
}

Analysis:

Based on https://github.com/lightning/bolts/blob/master/03-transactions.md#to_remote-output the witness should be <remote_sig> (followed by the redeemscript)

ksedgwic commented 8 months ago

Comparing two similar commitments

Comparing failed operation above (F) to similar successful instance (A):

Observations:

The good channel's outputs are spent by:

The troubled commitment's main outputs are:

The witness for A's to_remote is:

3045022100f5bad7155179820b4c74107a5c878a94dfdd61bd5561710546b5b4f5663ace8202203493a886ead7c11d2c04f31434e02338f68a31e6c9dcb18f15fbe50f99e0b13e01
2103e20728952d387266bbec58a0b608952124baa9dd58e6c339e52ec7115bb54501ad51b2

The script decodes as:

bitcoin@home5:~$ bitcoin-cli decodescript 2103e20728952d387266bbec58a0b608952124baa9dd58e6c339e52ec7115bb54501ad51b2
{
  "asm": "03e20728952d387266bbec58a0b608952124baa9dd58e6c339e52ec7115bb54501 OP_CHECKSIGVERIFY 1 OP_CHECKSEQUENCEVERIFY",
  "desc": "raw(2103e20728952d387266bbec58a0b608952124baa9dd58e6c339e52ec7115bb54501ad51b2)#7kdpwq3z",
  "type": "nonstandard",
  "p2sh": "3MmR7DiFemknUa1vQoE3ycri2ahU7hTR9b",
  "segwit": {
    "asm": "0 b61d3aec9892251b2aaeb5ce5600d4477090a9ef7e59ea11156edd1b4dcde2d9",
    "desc": "wsh(and_v(v:pk(03e20728952d387266bbec58a0b608952124baa9dd58e6c339e52ec7115bb54501),older(1)))#9pt2xcnl",
    "hex": "0020b61d3aec9892251b2aaeb5ce5600d4477090a9ef7e59ea11156edd1b4dcde2d9",
    "address": "bc1qkcwn4mycjgj3k24wkh89vqx5gacfp2000ev75yg4dmw3knwdutvsa5fh5j",
    "type": "witness_v0_scripthash",
    "p2sh-segwit": "32gXVyAjbrDhKb8iyAKh7xiYiZKeuekto3"
  }
}

The witness for F's to_remote is:

3045022100eba3c7db03e7be73a932d39816f10be376a79fb3ac2b960617a3331c5212ef0802201aaee301beac012ccd413a3ea6dbcd8edbf1ae3c26ccfc2ab979e70c352fc19b01
020d0f6142c6ad7c190875838f7a57bcfdcceb6e7bcc253849d038a8e6d847f333

The script is wrong

ksedgwic commented 8 months ago

I think the issue is related to the uniclosekeys argument to SignWithdrawal. The output in question is being spent and it is being identified as the output of a prior unilateral close. I suspect we need to deal with the anchors case explicitly ...

devrandom commented 8 months ago

created https://gitlab.com/lightning-signer/validating-lightning-signer/-/issues/444

devrandom commented 8 months ago

I analyzed the problem in the issue linked above. The issue is that we are missing the redeemscript in the witness stack for the anchors case.

I'm surprised that this case is not covered by the CLN system tests.

The script is wrong

That witness element would have been correct if this was non-anchors (p2wpkh), but it's indeed wrong for the anchors case (p2wsh).

ksedgwic commented 8 months ago

I improved the VLS debugging of Unilateral Close Info and slightly modified a CLN integration test to expose this issue in integration testing: https://gitlab.com/lightning-signer/vls-hsmd/-/merge_requests/136

devrandom commented 8 months ago

https://github.com/lightning-signer/c-lightning/compare/798ace6e1e17de8b2f46b6c006919422874a5a49...b06db5636911cccc4bb3f5572a39b292acb13066

devrandom commented 8 months ago

fixed in https://gitlab.com/lightning-signer/validating-lightning-signer/-/merge_requests/585

ksedgwic commented 8 months ago

https://gitlab.com/lightning-signer/validating-lightning-signer/-/merge_requests/585 merged