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.

Sign up for GitHub

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

Jump to bottom

Settling a hold invoice while the sender is offline results in the sender not persisting the preimage #3135

Closed
Jawshua opened this issue May 29, 2019 · 2 comments
Closed

Settling a hold invoice while the sender is offline results in the sender not persisting the preimage #3135

Jawshua opened this issue May 29, 2019 · 2 comments

Comments

@Jawshua
Copy link

Jawshua commented May 29, 2019

Background

When issuing a settleinvoice call when the sender of the payment is offline, the preimage will correctly be sent once the sender comes back online, but it is not persisted in the payments database and does not appear in listpayments

Your environment

  • Simnet running on the docker environment found in lnd/docker
  • lnd 0.6.1-beta commit=v0.6.1-beta-165-g28fdf9712d88c104ca039dc56d5242d3822c00d0
  • Linux inside Docker for Mac
    • Linux dc8760e2cbf6 4.9.93-linuxkit-aufs 1 SMP Wed Jun 6 16:55:56 UTC 2018 x86_64 Linux
    • Docker Version 18.06.1-ce-mac73 (26764)
    • macOS 10.14.4
  • btcd version 0.12.0-beta (built from source on 2018-05-28)

Steps to reproduce

Preimage:      12345678901234567890123456789032
Preimage Hex:  3132333435363738393031323334353637383930313233343536373839303332
Preimage Hash: dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521

Add the HODL invoice on Alice:

$ docker exec -it alice lncli --network simnet addholdinvoice dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521

{
	"pay_req": "lnsb1pwwuh5zpp5m4p5gdz3j26gljwkxktzp5j4kc24n4392lu9tudutl6f5kz5x5ssdqqcqzpg0vmqhwuutj2m0a6ukxqffqkzlae7jgrjhj2k3yfd29df5794tedzs6sj0ues5e0mmup935alsc7w6vxhgnk04j64pa76yelhljklhpsppf5rc8"
}

Pay the HODL invoice on Bob:

$ docker exec -it bob lncli --network simnet payinvoice --amt 1000 lnsb1pwwuh5zpp5m4p5gdz3j26gljwkxktzp5j4kc24n4392lu9tudutl6f5kz5x5ssdqqcqzpg0vmqhwuutj2m0a6ukxqffqkzlae7jgrjhj2k3yfd29df5794tedzs6sj0ues5e0mmup935alsc7w6vxhgnk04j64pa76yelhljklhpsppf5rc8

Description:
Amount (in satoshis): 1000
Destination: 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde

Cmd/Ctrl+C the payinvoice CLI and shut down bob:

$ docker stop bob

Settle the invoice on Alice:

$ docker exec -it alice lncli --network simnet settleinvoice 3132333435363738393031323334353637383930313233343536373839303332

{}

Start bob:

$ docker start bob

Expected behaviour

Running listpayments on bob should reveal the preimage.

Actual behaviour

$ docker exec -it bob lncli --network simnet listpayments

{
    "payments": [
        {
            "payment_hash": "dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521",
            "value": "1000",
            "creation_date": "1559125661",
            "path": [
                "037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde"
            ],
            "fee": "0",
            "payment_preimage": "0000000000000000000000000000000000000000000000000000000000000000",
            "value_sat": "1000",
            "value_msat": "1000000"
        }
    ]
}

$ docker exec -it alice lncli --network simnet lookupinvoice 
dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521
{
    "memo": "",
    "receipt": null,
    "r_preimage": "MTIzNDU2Nzg5MDEyMzQ1Njc4OTAxMjM0NTY3ODkwMzI=",
    "r_hash": "3UNENFGStI/J1jWWINJVthVZ1iVX+FXxvF/0mlhUNSE=",
    "value": "0",
    "settled": true,
    "creation_date": "1559125634",
    "settle_date": "1559125754",
    "payment_request": "lnsb1pwwuh5zpp5m4p5gdz3j26gljwkxktzp5j4kc24n4392lu9tudutl6f5kz5x5ssdqqcqzpg0vmqhwuutj2m0a6ukxqffqkzlae7jgrjhj2k3yfd29df5794tedzs6sj0ues5e0mmup935alsc7w6vxhgnk04j64pa76yelhljklhpsppf5rc8",
    "description_hash": null,
    "expiry": "3600",
    "fallback_addr": "",
    "cltv_expiry": "40",
    "route_hints": [
    ],
    "private": false,
    "add_index": "9",
    "settle_index": "5",
    "amt_paid": "1000000",
    "amt_paid_sat": "1000",
    "amt_paid_msat": "1000000",
    "state": "SETTLED"
}

Logs

Alice

2019-05-29 10:29:23.415 [INF] PEER: NodeKey(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094) loading ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.416 [DBG] CNCT: New ChainEventSubscription(id=7) for ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.416 [INF] HSWC: Removing channel link with ChannelID(77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df)
2019-05-29 10:29:23.416 [INF] HSWC: ChannelLink(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0) is starting
2019-05-29 10:29:23.416 [INF] HSWC: Trimming open circuits for chan_id=9796:1:0, start_htlc_id=1
2019-05-29 10:29:23.416 [INF] HSWC: Adding live link chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, short_chan_id=9796:1:0
2019-05-29 10:29:23.416 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.417 [INF] HSWC: HTLC manager for ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0) started, bandwidth=4889950000 mSAT
2019-05-29 10:29:23.417 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.417 [DBG] SRVR: Notifying that peer 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524 is online
2019-05-29 10:29:23.417 [DBG] PEER: Sending ChannelReestablish(next_local_height=16, remote_tail_height=15) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.417 [DBG] DISC: Peer=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094 is now online, proceeding to send pending messages
2019-05-29 10:29:23.417 [DBG] DISC: Requesting offline notification for peer=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094
2019-05-29 10:29:23.417 [DBG] DISC: Successfully sent ChannelUpdate message for channel=9796:1:0 with peer=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094 upon reconnection
2019-05-29 10:29:23.417 [INF] SRVR: Negotiated chan series queries with 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094
2019-05-29 10:29:23.417 [INF] DISC: Creating new GossipSyncer for peer=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094
2019-05-29 10:29:23.417 [DBG] DISC: Starting GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094)
2019-05-29 10:29:23.417 [DBG] DISC: Attempting initial historical sync with GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094)
2019-05-29 10:29:23.417 [DBG] PEER: Sending ChannelUpdate(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, short_chan_id=10770815905759232, mflags=00000001, cflags=00000001, update_time=2019-05-28 14:28:34 +0000 UTC) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.417 [DBG] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): state=chansSynced, type=PassiveSync
2019-05-29 10:29:23.417 [DBG] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): state=syncingChans, type=PassiveSync
2019-05-29 10:29:23.417 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): requesting new chans from height=0 and 4294967295 blocks after
2019-05-29 10:29:23.417 [DBG] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): state=waitingQueryRangeReply, type=PassiveSync
2019-05-29 10:29:23.418 [DBG] PEER: Sending QueryChannelRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, start_height=0, num_blocks=4294967295) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.418 [DBG] PEER: Received ChannelUpdate(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, short_chan_id=10770815905759232, mflags=00000001, cflags=00000000, update_time=2019-05-28 14:28:33 +0000 UTC) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.418 [DBG] PEER: Received ChannelReestablish(next_local_height=16, remote_tail_height=15) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.418 [DBG] PEER: Received QueryChannelRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, start_height=0, num_blocks=4294967295) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.418 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): filtering chan range: start_height=0, num_blocks=4294967295
2019-05-29 10:29:23.418 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): sending final chan range chunk, size=1
2019-05-29 10:29:23.418 [DBG] PEER: Sending ReplyChannelRange(complete=1, encoding=0, num_chans=1) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.418 [INF] HSWC: Received re-establishment message from remote side for channel(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.421 [DBG] PEER: Received ReplyChannelRange(complete=1, encoding=0, num_chans=1) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.422 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): buffering chan range reply of size=1
2019-05-29 10:29:23.422 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): filtering through 1 chans
2019-05-29 10:29:23.422 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): remote peer has no new chans
2019-05-29 10:29:23.422 [DBG] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): state=chansSynced, type=PassiveSync
2019-05-29 10:29:23.422 [DBG] DISC: Initial historical sync completed
2019-05-29 10:29:23.422 [DBG] DISC: Attempting to transition 3 passive GossipSyncers to active
2019-05-29 10:29:23.422 [DBG] DISC: Transitioning passive GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094) to active
2019-05-29 10:29:23.422 [DBG] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): transitioning from PassiveSync to ActiveSync
2019-05-29 10:29:23.422 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): applying gossipFilter(start=2019-05-29 10:29:23.4226021 +0000 UTC m=+35641.083470401, end=2155-07-05 16:57:38.4226021 +0000 UTC m=+4295002936.083470401)
2019-05-29 10:29:23.422 [DBG] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): state=chansSynced, type=ActiveSync
2019-05-29 10:29:23.422 [DBG] PEER: Sending GossipTimestampRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, first_stamp=2019-05-29 10:29:23 +0000 UTC, stamp_range=4294967295) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.423 [DBG] PEER: Received GossipTimestampRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, first_stamp=2019-05-29 10:29:23 +0000 UTC, stamp_range=4294967295) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.423 [DBG] CHDB: ChanUpdatesInHorizon hit percentage: NaN (0/0)
2019-05-29 10:29:23.423 [INF] DISC: GossipSyncer(0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094): applying new update horizon: start=2019-05-29 10:29:23 +0000 UTC, end=2155-07-05 16:57:38 +0000 UTC, backlog_size=0
2019-05-29 10:29:23.424 [DBG] PEER: Received NodeAnnouncement(node=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094, update_time=2019-05-29 10:29:23 +0000 UTC) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.428 [INF] CRTR: Updated vertex data for node=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094
2019-05-29 10:29:23.430 [DBG] DISC: Removed stale ChannelUpdate message for channel=9796:1:0 with peer=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094
2019-05-29 10:29:23.430 [DBG] HSWC: ChannelLink(9796:1:0) loaded 5 fwd pks
2019-05-29 10:29:23.430 [DBG] DISC: No pending messages left for peer=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094
2019-05-29 10:29:23.444 [DBG] INVC: Invoice(3131313437343135373039393939343331313134373431353730393939393433): accepting duplicate payment to accepted invoice, amt=1000000 mSAT, expiry=9847
2019-05-29 10:29:23.445 [DBG] INVC: Hodl subscribe for 3131313437343135373039393939343331313134373431353730393939393433
2019-05-29 10:29:23.457 [DBG] INVC: Invoice(fb7c9a0dc81368f5419f209a4d270ff07b7dda812a353ae4daec220945b3494d): accepting duplicate payment to accepted invoice, amt=1000000 mSAT, expiry=9847
2019-05-29 10:29:23.457 [DBG] INVC: Hodl subscribe for fb7c9a0dc81368f5419f209a4d270ff07b7dda812a353ae4daec220945b3494d
2019-05-29 10:29:23.469 [DBG] INVC: Invoice(1c4989ffc8c191936e4cd2eae432c46acfa45d27c5f0f3c02262eec155e7d6a1): accepting duplicate payment to accepted invoice, amt=1000000 mSAT, expiry=9847
2019-05-29 10:29:23.469 [DBG] INVC: Hodl subscribe for 1c4989ffc8c191936e4cd2eae432c46acfa45d27c5f0f3c02262eec155e7d6a1
2019-05-29 10:29:23.481 [DBG] INVC: Invoice(b9305bd17191d39016c7dcb37de62c68f9ac086fe2573ffa184a149993a6c5c7): accepting duplicate payment to accepted invoice, amt=1000000 mSAT, expiry=9847
2019-05-29 10:29:23.481 [DBG] INVC: Hodl subscribe for b9305bd17191d39016c7dcb37de62c68f9ac086fe2573ffa184a149993a6c5c7
2019-05-29 10:29:23.493 [DBG] INVC: Invoice(dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521): accepting duplicate payment to settled invoice, amt=1000000 mSAT, expiry=9847
2019-05-29 10:29:23.493 [DBG] HSWC: ChannelLink(9796:1:0) Received hodl settle event for dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521
2019-05-29 10:29:23.493 [INF] HSWC: ChannelLink(9796:1:0) settling htlc dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521 as exit hop
2019-05-29 10:29:23.494 [DBG] PEER: Sending UpdateFulfillHTLC(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, id=8, pre_image=3132333435363738393031323334353637383930313233343536373839303332) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.511 [DBG] PEER: Sending CommitSig(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, num_htlcs=0) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.531 [DBG] PEER: Received RevokeAndAck(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, rev=a9dfe01abf4b3479035df3783c396bc1da34ec7f9719c128e64c92476ed9c205, next_point=030788c9d48c717214c592aa006a48499f116866c2d42fe43db046b6bb5f1042bd) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.549 [DBG] PEER: Received CommitSig(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, num_htlcs=0) from 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:23.562 [DBG] PEER: Sending RevokeAndAck(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, rev=12cbb4094b032323227193eaeb52e5ffec7159445af05cacc767056b4a8de403, next_point=025e43d606fc18a780ba57dd3e9ebfcac9627580fb4d3224cb511826d0d9d7c018) to 0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094@192.168.32.4:45524
2019-05-29 10:29:25.518 [DBG] HSWC: Sent 5000 satoshis and received 5000 satoshis in the last 10 seconds (1.600000 tx/sec)

Bob

2019-05-29 10:29:23.406 [INF] PEER: NodeKey(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde) loading ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.403 [ERR] CRTR: Resuming payment with hash dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521 failed: pre-built route already tried.
2019-05-29 10:29:23.407 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.407 [INF] HSWC: Removing channel link with ChannelID(77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df)
2019-05-29 10:29:23.407 [INF] HSWC: ChannelLink(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0) is starting
2019-05-29 10:29:23.409 [INF] HSWC: Trimming open circuits for chan_id=9796:1:0, start_htlc_id=9
2019-05-29 10:29:23.409 [INF] HSWC: Adding live link chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, short_chan_id=9796:1:0
2019-05-29 10:29:23.409 [DBG] SRVR: Notifying that peer 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735 is online
2019-05-29 10:29:23.409 [DBG] DISC: Peer=037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde is now online, proceeding to send pending messages
2019-05-29 10:29:23.410 [DBG] DISC: Requesting offline notification for peer=037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde
2019-05-29 10:29:23.409 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.409 [INF] HSWC: HTLC manager for ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0) started, bandwidth=4896000000 mSAT
2019-05-29 10:29:23.410 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.410 [INF] SRVR: Negotiated chan series queries with 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde
2019-05-29 10:29:23.410 [DBG] DISC: Successfully sent ChannelUpdate message for channel=9796:1:0 with peer=037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde upon reconnection
2019-05-29 10:29:23.410 [DBG] PEER: Sending ChannelUpdate(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, short_chan_id=10770815905759232, mflags=00000001, cflags=00000000, update_time=2019-05-28 14:28:33 +0000 UTC) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.411 [INF] DISC: Creating new GossipSyncer for peer=037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde
2019-05-29 10:29:23.412 [DBG] DISC: Starting GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde)
2019-05-29 10:29:23.412 [DBG] DISC: Attempting initial historical sync with GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde)
2019-05-29 10:29:23.412 [DBG] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): state=chansSynced, type=PassiveSync
2019-05-29 10:29:23.412 [DBG] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): state=syncingChans, type=PassiveSync
2019-05-29 10:29:23.412 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): requesting new chans from height=0 and 4294967295 blocks after
2019-05-29 10:29:23.412 [DBG] PEER: Sending ChannelReestablish(next_local_height=16, remote_tail_height=15) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.412 [DBG] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): state=waitingQueryRangeReply, type=PassiveSync
2019-05-29 10:29:23.413 [DBG] PEER: Sending QueryChannelRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, start_height=0, num_blocks=4294967295) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.419 [DBG] PEER: Received ChannelReestablish(next_local_height=16, remote_tail_height=15) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.419 [DBG] PEER: Received ChannelUpdate(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, short_chan_id=10770815905759232, mflags=00000001, cflags=00000001, update_time=2019-05-28 14:28:34 +0000 UTC) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.420 [DBG] PEER: Received QueryChannelRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, start_height=0, num_blocks=4294967295) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.420 [DBG] PEER: Received ReplyChannelRange(complete=1, encoding=0, num_chans=1) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.420 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): buffering chan range reply of size=1
2019-05-29 10:29:23.420 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): filtering through 1 chans
2019-05-29 10:29:23.420 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): filtering chan range: start_height=0, num_blocks=4294967295
2019-05-29 10:29:23.420 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): remote peer has no new chans
2019-05-29 10:29:23.420 [DBG] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): state=chansSynced, type=PassiveSync
2019-05-29 10:29:23.420 [DBG] DISC: Initial historical sync completed
2019-05-29 10:29:23.419 [INF] HSWC: Received re-establishment message from remote side for channel(df721c64c6aa566dd58264e70adaa68bf54bbf4eb395580c590e4d2ed51dc477:0)
2019-05-29 10:29:23.420 [DBG] DISC: Attempting to transition 3 passive GossipSyncers to active
2019-05-29 10:29:23.421 [DBG] DISC: Transitioning passive GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde) to active
2019-05-29 10:29:23.421 [DBG] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): transitioning from PassiveSync to ActiveSync
2019-05-29 10:29:23.420 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): sending final chan range chunk, size=1
2019-05-29 10:29:23.421 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): applying gossipFilter(start=2019-05-29 10:29:23.4213059 +0000 UTC m=+2.144058101, end=2155-07-05 16:57:38.4213059 +0000 UTC m=+4294967297.144058101)
2019-05-29 10:29:23.421 [DBG] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): state=chansSynced, type=ActiveSync
2019-05-29 10:29:23.421 [DBG] PEER: Sending ReplyChannelRange(complete=1, encoding=0, num_chans=1) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.423 [DBG] PEER: Sending GossipTimestampRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, first_stamp=2019-05-29 10:29:23 +0000 UTC, stamp_range=4294967295) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.423 [DBG] PEER: Received GossipTimestampRange(chain_hash=683e86bd5c6d110d91b94b97137ba6bfe02dbbdb8e3dff722a669b5d69d77af6, first_stamp=2019-05-29 10:29:23 +0000 UTC, stamp_range=4294967295) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.423 [DBG] CHDB: ChanUpdatesInHorizon hit percentage: NaN (0/0)
2019-05-29 10:29:23.423 [INF] DISC: GossipSyncer(037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde): applying new update horizon: start=2019-05-29 10:29:23 +0000 UTC, end=2155-07-05 16:57:38 +0000 UTC, backlog_size=1
2019-05-29 10:29:23.424 [DBG] PEER: Sending NodeAnnouncement(node=0342905d9277c272ebf1e493d6cd8b3a684132e9b41834bc0bcd40a25054113094, update_time=2019-05-29 10:29:23 +0000 UTC) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.433 [DBG] HSWC: ChannelLink(9796:1:0) loaded 0 fwd pks
2019-05-29 10:29:23.495 [DBG] PEER: Received UpdateFulfillHTLC(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, id=8, pre_image=3132333435363738393031323334353637383930313233343536373839303332) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.512 [DBG] PEER: Received CommitSig(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, num_htlcs=0) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.512 [INF] SRVR: Adding preimage=3132333435363738393031323334353637383930313233343536373839303332 to witness cache
2019-05-29 10:29:23.531 [DBG] PEER: Sending RevokeAndAck(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, rev=a9dfe01abf4b3479035df3783c396bc1da34ec7f9719c128e64c92476ed9c205, next_point=030788c9d48c717214c592aa006a48499f116866c2d42fe43db046b6bb5f1042bd) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.548 [DBG] PEER: Sending CommitSig(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, num_htlcs=0) to 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.562 [DBG] PEER: Received RevokeAndAck(chan_id=77c41dd52e4d0e590c5895b34ebf4bf58ba6da0ae76482d56d56aac6641c72df, rev=12cbb4094b032323227193eaeb52e5ffec7159445af05cacc767056b4a8de403, next_point=025e43d606fc18a780ba57dd3e9ebfcac9627580fb4d3224cb511826d0d9d7c018) from 037bc5023e45478fcbbdb0a408c7004d09debf4fb234d22578ca0354b0dc1c2bde@192.168.32.2:9735
2019-05-29 10:29:23.574 [DBG] HSWC: ChannelLink(9796:1:0): settle-fail-filter &{1 [0]}
2019-05-29 10:29:23.574 [DBG] HSWC: Closed completed SETTLE circuit for dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521: (0:0:0, 4001) <-> (9796:1:0, 8)
2019-05-29 10:29:23.588 [DBG] HSWC: Tearing down open circuit with SETTLE pkt, removing circuit=(Chan ID=0:0:0, HTLC ID=4001) with keystone=(Chan ID=9796:1:0, HTLC ID=8)
2019-05-29 10:29:23.600 [DBG] HSWC: Closed completed SETTLE circuit for dd4344345192b48fc9d6359620d255b61559d62557f855f1bc5ff49a58543521: (0:0:0, 4001) <-> (9796:1:0, 8)
2019-05-29 10:29:23.600 [ERR] HSWC: Cannot find pending payment with ID 4001
2019-05-29 10:29:33.306 [DBG] HSWC: Sent 5000 satoshis and received 5000 satoshis in the last 10 seconds (1.600000 tx/sec)
@Roasbeef
Copy link
Member

This will be fixed with #2762

@halseth
Copy link
Contributor

halseth commented Jun 11, 2019

Fixed by #2762

@halseth halseth closed this as completed Jun 11, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Roasbeef @halseth @Jawshua