Warning message support #4364
Merged
Warning message support #4364
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
rustyrussell
added
enhancement
protocol
rustyrussell
force-pushed
the
guilt/soft-errors-prep
branch
2 times, most recently
from
36f78f5
to
9bf8e5d
Compare
|
Rerunning what appears to be a flake. Documenting it here in case it isn't:
```
2021-02-01T05:23:27.3753819Z lightningd-1: 2021-02-01T05:12:02.835Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-connectd: Connect OUT
2021-02-01T05:23:27.3755615Z lightningd-1: 2021-02-01T05:12:02.836Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-connectd: peer_out WIRE_INIT
2021-02-01T05:23:27.3757443Z lightningd-1: 2021-02-01T05:12:02.836Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-connectd: peer_in WIRE_INIT
2021-02-01T05:23:27.3759333Z lightningd-1: 2021-02-01T05:12:02.836Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-chan#1: Peer has reconnected, state CHANNELD_NORMAL
2021-02-01T05:23:27.3761535Z lightningd-2: 2021-02-01T05:12:02.836Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: pid 62171, msgfd 36
2021-02-01T05:23:27.3763093Z lightningd-2: 2021-02-01T05:12:02.836Z DEBUG hsmd: Client: Received message 10 from client
2021-02-01T05:23:27.3764133Z lightningd-2: 2021-02-01T05:12:02.836Z DEBUG hsmd: Client: Received message 9 from client
2021-02-01T05:23:27.3765028Z lightningd-2: 2021-02-01T05:12:02.836Z DEBUG hsmd: new_client: 2
2021-02-01T05:23:27.3766613Z lightningd-1: 2021-02-01T05:12:02.847Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: pid 62172, msgfd 43
2021-02-01T05:23:27.3768968Z lightningd-1: 2021-02-01T05:12:02.847Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-chan#1: Already have funding locked in
2021-02-01T05:23:27.3771042Z lightningd-1: 2021-02-01T05:12:02.847Z DEBUG lightningd: Adding block 103: 64573c9ae353c453b3d3ab5ee07c8a1246be1afe632f70f53840a718da730d75
2021-02-01T05:23:27.3773286Z lightningd-1: 2021-02-01T05:12:02.848Z DEBUG wallet: Owning output 0 995433sat (SEGWIT) txid 2a5d02d1f465eddbe45cc91bc5334ec81a1c776547e3c11f746252f91a9d4bb3 CONFIRMED
2021-02-01T05:23:27.3774964Z lightningd-1: 2021-02-01T05:12:02.849Z DEBUG hsmd: Client: Received message 9 from client
2021-02-01T05:23:27.3775870Z lightningd-1: 2021-02-01T05:12:02.849Z DEBUG hsmd: new_client: 1
2021-02-01T05:23:27.3777448Z lightningd-2: 2021-02-01T05:12:02.858Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: peer_out WIRE_ERROR
2021-02-01T05:23:27.3780345Z lightningd-1: 2021-02-01T05:12:02.859Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-chan#1: Got depth change 0->1 for 2a5d02d1f465eddbe45cc91bc5334ec81a1c776547e3c11f746252f91a9d4bb3
2021-02-01T05:23:27.3784285Z lightningd-1: 2021-02-01T05:12:02.859Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-chan#1: Funding tx 2a5d02d1f465eddbe45cc91bc5334ec81a1c776547e3c11f746252f91a9d4bb3 depth 1 of 1
2021-02-01T05:23:27.3786640Z lightningd-2: 2021-02-01T05:12:02.859Z DEBUG hsmd: Client: Received message 18 from client
2021-02-01T05:23:27.3788516Z lightningd-2: 2021-02-01T05:12:02.859Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: Handed peer, entering loop
2021-02-01T05:23:27.3791042Z lightningd-2: 2021-02-01T05:12:02.859Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER
2021-02-01T05:23:27.3795451Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: init LOCAL: remote_per_commit = 020b2bb4220acc4114c47375e9b71e072f7cac127e1bb453d49595699958cfa9e4, old_remote_per_commit = 0371b7132cde15d9f729b6c24b08d808b59599806f7af5e8be6811a0874c3c0977 next_idx_local = 1 next_idx_remote = 1 revocations_received = 0 feerates { SENT_ADD_ACK_REVOCATION:7500 } range 1875-150000
2021-02-01T05:23:27.3799296Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: option_static_remotekey = 1
2021-02-01T05:23:27.3800955Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG hsmd: Client: Received message 18 from client
2021-02-01T05:23:27.3802005Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG hsmd: Client: Received message 18 from client
2021-02-01T05:23:27.3803784Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: peer_out WIRE_CHANNEL_REESTABLISH
2021-02-01T05:23:27.3806157Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: peer_in WIRE_ERROR
2021-02-01T05:23:27.3809478Z lightningd-1: 2021-02-01T05:12:02.863Z INFO 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-chan#1: Peer transient failure in CHANNELD_NORMAL: channeld WARNING: error channel b34b9d1af95262741fc1e34765771c1ac84e33c51bc95ce4dbed65f4d1025d2b: Forcibly closed by `close` command timeout
2021-02-01T05:23:27.3812413Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-chan#1: Will try reconnect in 60 seconds
2021-02-01T05:23:27.3814586Z lightningd-1: 2021-02-01T05:12:02.863Z DEBUG 022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59-channeld-chan#1: Status closed, but not exited. Killing
2021-02-01T05:23:27.3816695Z lightningd-2: 2021-02-01T05:12:02.863Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: peer_in WIRE_CHANNEL_REESTABLISH
2021-02-01T05:23:27.3819385Z lightningd-2: 2021-02-01T05:12:02.864Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: Rejecting WIRE_CHANNEL_REESTABLISH for unknown channel_id b34b9d1af95262741fc1e34765771c1ac84e33c51bc95ce4dbed65f4d1025d2b
2021-02-01T05:23:27.3822309Z lightningd-2: 2021-02-01T05:12:02.864Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: peer_out WIRE_ERROR
2021-02-01T05:23:27.3824538Z lightningd-2: 2021-02-01T05:12:02.864Z INFO 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: Peer connection lost
2021-02-01T05:23:27.3827220Z lightningd-2: 2021-02-01T05:12:02.864Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-openingd-chan#2: Status closed, but not exited. Killing
2021-02-01T05:23:27.3829606Z lightningd-2: 2021-02-01T05:12:02.864Z INFO 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-chan#2: Owning subdaemon openingd died (62208)
2021-02-01T05:23:27.3831916Z lightningd-2: 2021-02-01T05:12:05.706Z DEBUG 0266e4598d1d3c415f572a8488830b60f7e744ed9235eb0b1ba93283b315c03518-chan#1: Will try reconnect in 4 seconds
=========================== short test summary info ============================ |
|
Found three more flaky tests:
|
We construct the route manually so we may not have the channel_announcement yet. But we can get an update from the error packet, which can lead to: ``` 2021-01-29T01:38:23.4767334Z ValueError: 2021-01-29T01:38:23.4767987Z Node errors: 2021-01-29T01:38:23.4768767Z - lightningd-1: had bad gossip messages 2021-01-29T01:38:23.4769512Z Global errors: 2021-01-29T01:38:23.4770300Z 2021-01-29T01:38:23.4771109Z contrib/pyln-testing/pyln/testing/fixtures.py:197: ValueError ... 2021-01-29T01:38:23.7820197Z lightningd-1: 2021-01-29T01:26:57.460Z DEBUG gossipd: Extracted channel_update 01027217b3086ad9f3dee1fa55b94c5fd2a4b0637bec70ba727ba4151a8de5173ddc749db3502d41ab0ae164addc8fd013d2088b6a12a2f478ae0affa94d76d8845c06226e46111a0b59caaf126043eb5bbf28c34f3a5e332a1fc7b2b73cf188910f000067000001000160136459010000060000000000000000000000010000000a000000003b023380 from onionreply 100d0000007500887217b3086ad9f3dee1fa55b94c5fd2a4b0637bec70ba727ba4151a8de5173ddc749db3502d41ab0ae164addc8fd013d2088b6a12a2f478ae0affa94d76d8845c06226e46111a0b59caaf126043eb5bbf28c34f3a5e332a1fc7b2b73cf188910f000067000001000160136459010000060000000000000000000000010000000a000000003b023380 2021-01-29T01:38:23.7837450Z lightningd-1: 2021-01-29T01:26:57.461Z DEBUG gossipd: Bad gossip order: WIRE_CHANNEL_UPDATE before announcement 103x1x1/0 ``` Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
This takes from the draft spec at lightning/bolts#834 Note that if this draft does not get included, the peer will simply ignore the warning message (we always close the connection afterwards anyway). Signed-off-by: Rusty Russell <rusty@rustcorp.com.au> Changelog-Added: Protocol: we now report the new (draft) warning message.
This is in line with the warnings draft, where all-zeroes in a channel_id is no longer special (i.e. it will be ignored). But gossipd would send these if it got upset with us, so it's best practice to ignore them for now anyway. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au> Changelog-Added: Protocol: we treat error messages from peer which refer to "all channels" as warnings, not errors.
Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
And make all the callers choose which one. In general, I prefer warn, which lets them reconnect and try again, however some places are either stated that they must be errors in the spec itself, or in openingd where we abandon the channel when we close the connection anyway. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au> Changelog-Changed: Protocol: we now send warning messages and close the connection, except on unrecoverable errors.
rustyrussell
force-pushed
the
guilt/soft-errors-prep
branch
from
9bf8e5d
to
06d43e8
Compare
No more sending "all-channel" errors; in particular, gossipd now only sends warnings (which make us hang up), not errors, and peer_connected rejections are warnings (and disconnect), not errors. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au> Changelog-Changed: Plugins: `peer_connected` rejections now send a warning, not an error, to the peer.
rustyrussell
force-pushed
the
guilt/soft-errors-prep
branch
from
06d43e8
to
ce550df
Compare
|
Fixed erroneous case where we would send an error in openingd, but not close channel. Rebased. |
Since we turned many errors into warnings, we want our tests to fail when they happen unexpectedly. We make WARNING clear in the strings we print, too, to help out. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
rustyrussell
force-pushed
the
guilt/soft-errors-prep
branch
from
ce550df
to
f8092ab
Compare
|
ACK f8092ab |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
See lightning/bolts#834 for the proposal. This should be fairly non-controversial, as it is backward compatible, and if necessary we can disable the actual sending of warnings before release.