diff --git a/channeld/channeld.c b/channeld/channeld.c index a2ee13dec..07f1040c6 100644 --- a/channeld/channeld.c +++ b/channeld/channeld.c @@ -3313,7 +3313,7 @@ static void resume_splice_negotiation(struct peer *peer, type = fromwire_peektype(msg); - if (handle_peer_error(peer->pps, &peer->channel_id, msg)) + if (handle_peer_error_or_warning(peer->pps, msg)) return; if (type != WIRE_TX_SIGNATURES) @@ -4090,7 +4090,7 @@ static void peer_in(struct peer *peer, const u8 *msg) { enum peer_wire type = fromwire_peektype(msg); - if (handle_peer_error(peer->pps, &peer->channel_id, msg)) + if (handle_peer_error_or_warning(peer->pps, msg)) return; /* Must get channel_ready before almost anything. */ @@ -4743,7 +4743,7 @@ static void peer_reconnect(struct peer *peer, "Expected reestablish, got: %s", tal_hex(tmpctx, msg)); } - } while (handle_peer_error(peer->pps, &peer->channel_id, msg) || + } while (handle_peer_error_or_warning(peer->pps, msg) || capture_premature_msg(&premature_msgs, msg)); /* Initialize here in case we don't read it below! */ diff --git a/closingd/closingd.c b/closingd/closingd.c index ef13af7b8..cb4eca655 100644 --- a/closingd/closingd.c +++ b/closingd/closingd.c @@ -116,15 +116,14 @@ static struct bitcoin_tx *close_tx(const tal_t *ctx, /* Handle random messages we might get, returning the first non-handled one. */ static u8 *closing_read_peer_msg(const tal_t *ctx, - struct per_peer_state *pps, - const struct channel_id *channel_id) + struct per_peer_state *pps) { for (;;) { u8 *msg; clean_tmpctx(); msg = peer_read(ctx, pps); - if (!handle_peer_error(pps, channel_id, msg)) + if (!handle_peer_error_or_warning(pps, msg)) return msg; } } @@ -255,7 +254,7 @@ receive_offer(struct per_peer_state *pps, /* Wait for them to say something interesting */ do { - msg = closing_read_peer_msg(tmpctx, pps, channel_id); + msg = closing_read_peer_msg(tmpctx, pps); /* BOLT #2: * diff --git a/common/interactivetx.c b/common/interactivetx.c index b3cb21f18..61e3056dc 100644 --- a/common/interactivetx.c +++ b/common/interactivetx.c @@ -97,8 +97,7 @@ static u8 *read_next_msg(const tal_t *ctx, u8 *msg = NULL; for (;;) { - char *desc; - bool warning; + const char *desc; enum peer_wire t; /* Prevent runaway memory usage from many messages */ @@ -118,20 +117,19 @@ static u8 *read_next_msg(const tal_t *ctx, continue; /* A helper which decodes an error. */ - if (is_peer_error(msg, msg, &state->channel_id, - &desc, &warning)) { - /* In this case, is_peer_error returns true, but sets - * desc to NULL */ - if (!desc) - continue; + desc = is_peer_error(msg, msg); + if (desc) { + *error = tal_fmt(ctx, "They sent an error: %s", desc); - *error = tal_fmt(ctx, "They sent a %s: %s", - warning ? "warning" : "error", - desc); - - tal_free(msg); /* Return NULL so caller knows to stop negotiating. */ - return NULL; + return tal_free(msg); + } + + desc = is_peer_warning(msg, msg); + if (desc) { + status_info("They sent %s", desc); + tal_free(msg); + continue; } /* In theory, we're in the middle of an open/RBF/splice, but diff --git a/common/peer_failed.c b/common/peer_failed.c index 503de5319..13a97887d 100644 --- a/common/peer_failed.c +++ b/common/peer_failed.c @@ -80,23 +80,11 @@ void peer_failed_err(struct per_peer_state *pps, /* We're failing because peer sent us an error/warning message */ void peer_failed_received_errmsg(struct per_peer_state *pps, const char *desc, - const struct channel_id *channel_id, - bool warning, bool abort_restart) { u8 *msg; - /* LND sends "internal error" and we close the channel. But - * prior to 0.11 we would turn this into a warning, and they - * would recover after a reconnect. So we downgrade, but snark - * about it in the logs. */ - if (!warning && strends(desc, "internal error")) { - status_unusual("lnd sent 'internal error':" - " let's give it some space"); - warning = true; - } - msg = towire_status_peer_error(NULL, desc, warning, - abort_restart, NULL); + msg = towire_status_peer_error(NULL, desc, false, abort_restart, NULL); peer_billboard(true, "Received %s", desc); peer_fatal_continue(take(msg), pps); } diff --git a/common/peer_failed.h b/common/peer_failed.h index 0cff74b2a..c33c68d2d 100644 --- a/common/peer_failed.h +++ b/common/peer_failed.h @@ -36,8 +36,6 @@ void peer_failed_err(struct per_peer_state *pps, * channel_id means all channels. */ void peer_failed_received_errmsg(struct per_peer_state *pps, const char *desc, - const struct channel_id *channel_id, - bool soft_error, bool abort_restart) NORETURN; diff --git a/common/peer_status_wire.csv b/common/peer_status_wire.csv index d3c6ef0f8..cc3ffdf0e 100644 --- a/common/peer_status_wire.csv +++ b/common/peer_status_wire.csv @@ -5,6 +5,7 @@ msgtype,status_peer_error,0xFFF4 msgdata,status_peer_error,desc,wirestring, # Take a deep breath, then try reconnecting to the precious little snowflake. +# (Means we sent it, since we don't hang up if they send one) msgdata,status_peer_error,warning,bool, # From an abort, no reconnect but restart daemon msgdata,status_peer_error,abort_do_restart,bool, diff --git a/common/read_peer_msg.c b/common/read_peer_msg.c index 83c937cbb..c9a8837d2 100644 --- a/common/read_peer_msg.c +++ b/common/read_peer_msg.c @@ -12,66 +12,38 @@ #include #include -bool is_peer_error(const tal_t *ctx, const u8 *msg, - const struct channel_id *channel_id, - char **desc, bool *warning) +const char *is_peer_warning(const tal_t *ctx, const u8 *msg) { - struct channel_id err_chanid; - - if (fromwire_peektype(msg) == WIRE_ERROR) - *warning = false; - else if (fromwire_peektype(msg) == WIRE_WARNING) - *warning = true; - else - return false; - - *desc = sanitize_error(ctx, msg, &err_chanid); - - /* BOLT #1: - * - * The channel is referred to by `channel_id`, unless `channel_id` is - * 0 (i.e. all bytes are 0), in which case it refers to all channels. - * ... - * The receiving node: - * - upon receiving `error`: - * - if `channel_id` is all zero: - * - MUST fail all channels with the sending node. - * - otherwise: - * - MUST fail the channel referred to by `channel_id`, if that channel is with the sending node. - * - upon receiving `warning`: - * - SHOULD log the message for later diagnosis. - * - MAY disconnect. - * - MAY reconnect after some delay to retry. - * - MAY attempt `shutdown` if permitted at this point. - * - if no existing channel is referred to by `channel_id`: - * - MUST ignore the message. - */ - - /* FIXME: We don't actually free all channels at once, they'll - * have to error each in turn. */ - if (!channel_id_is_all(&err_chanid) - && !channel_id_eq(&err_chanid, channel_id)) - *desc = tal_free(*desc); - - return true; + if (fromwire_peektype(msg) != WIRE_WARNING) + return NULL; + /* connectd demuxes, so we only see it if channel_id is ours. */ + return sanitize_error(ctx, msg, NULL); } -bool handle_peer_error(struct per_peer_state *pps, - const struct channel_id *channel_id, - const u8 *msg TAKES) +const char *is_peer_error(const tal_t *ctx, const u8 *msg) { - char *err; - bool warning; - if (is_peer_error(tmpctx, msg, channel_id, &err, &warning)) { - /* Ignore unknown channel errors. */ - if (!err) { - if (taken(msg)) - tal_free(msg); - return true; - } + if (fromwire_peektype(msg) != WIRE_ERROR) + return NULL; + /* connectd demuxes, so we only see it if channel_id is ours. */ + return sanitize_error(ctx, msg, NULL); +} - /* We hang up when a warning is received. */ - peer_failed_received_errmsg(pps, err, channel_id, warning, false); +bool handle_peer_error_or_warning(struct per_peer_state *pps, + const u8 *msg TAKES) +{ + const char *err; + + err = is_peer_error(tmpctx, msg); + if (err) + peer_failed_received_errmsg(pps, err, false); + + /* Simply log incoming warnings */ + err = is_peer_warning(tmpctx, msg); + if (err) { + if (taken(msg)) + tal_free(msg); + status_info("Received %s", err); + return true; } return false; diff --git a/common/read_peer_msg.h b/common/read_peer_msg.h index 3c6e2faf8..a3d541803 100644 --- a/common/read_peer_msg.h +++ b/common/read_peer_msg.h @@ -9,30 +9,34 @@ struct channel_id; struct per_peer_state; /** - * is_peer_error - if it's an error, describe if it applies to this channel. + * is_peer_error - if it's an error, describe it. * @ctx: context to allocate return from. * @msg: the peer message. - * @channel_id: the channel id of the current channel. - * @desc: set to non-NULL if this describes a channel we care about. - * @warning: set to true if this is a warning, not an error. * - * If @desc is NULL, ignore this message. Otherwise, that's usually passed - * to peer_failed_received_errmsg(). + * If this returns non-NULL, it's usually passed to + * peer_failed_received_errmsg(). */ -bool is_peer_error(const tal_t *ctx, const u8 *msg, - const struct channel_id *channel_id, - char **desc, bool *warning); +const char *is_peer_error(const tal_t *ctx, const u8 *msg); /** - * handle_peer_error - simple handler for errors + * is_peer_warning - if it's a warning, describe it. + * @ctx: context to allocate return from. + * @msg: the peer message. + * + * If this returns non-NULL, it's usually logged. + */ +const char *is_peer_warning(const tal_t *ctx, const u8 *msg); + +/** + * handle_peer_error_or_warning - simple handler for errors / warnings * @pps: per-peer state. * @channel_id: the channel id of the current channel. * @msg: the peer message (only taken if returns true). * - * This returns true if it handled the packet. + * This returns true if it handled the packet (i.e. logs a warning). + * Doesn't return if it's an error. */ -bool handle_peer_error(struct per_peer_state *pps, - const struct channel_id *channel_id, - const u8 *msg TAKES); +bool handle_peer_error_or_warning(struct per_peer_state *pps, + const u8 *msg TAKES); #endif /* LIGHTNING_COMMON_READ_PEER_MSG_H */ diff --git a/common/wire_error.c b/common/wire_error.c index e4376924e..cdda76d66 100644 --- a/common/wire_error.c +++ b/common/wire_error.c @@ -118,7 +118,7 @@ char *sanitize_error(const tal_t *ctx, const u8 *errmsg, } return tal_fmt(ctx, "%s%s%s: %.*s", - warning ? "warning" : "error", + warning ? "WARNING" : "ERROR", channel_id_is_all(channel_id) ? "": " channel ", channel_id_is_all(channel_id) ? "" : type_to_string(tmpctx, struct channel_id, channel_id), diff --git a/lightningd/peer_control.c b/lightningd/peer_control.c index e3326b190..0ff438b7e 100644 --- a/lightningd/peer_control.c +++ b/lightningd/peer_control.c @@ -402,14 +402,22 @@ void channel_errmsg(struct channel *channel, if (err_for_them && !channel->error && !warning) channel->error = tal_dup_talarr(channel, u8, err_for_them); - /* Other implementations chose to ignore errors early on. Not - * surprisingly, they now spew out spurious errors frequently, - * and we would close the channel on them. We now support warnings - * for this case. */ - if (warning) { - channel_fail_transient(channel, "%s%s: %s", + /* LND sends "internal error" and we close the channel. But + * prior to 0.11 we would turn this into a warning, and they + * would recover after a reconnect. So we downgrade, but snark + * about it in the logs. */ + if (!err_for_them && strends(desc, "internal error")) { + channel_fail_transient(channel, "%s: %s", + channel->owner->name, + "lnd sent 'internal error':" + " let's give it some space"); + return; + } + + /* This is us, sending a warning. */ + if (warning) { + channel_fail_transient(channel, "%s sent %s", channel->owner->name, - warning ? " WARNING" : " (aborted)", desc); return; } @@ -446,13 +454,13 @@ void channel_errmsg(struct channel *channel, * CHANNELD_AWAITING_LOCKIN if we are fundee. */ if (!err_for_them && channel->opener == REMOTE && channel->state == CHANNELD_AWAITING_LOCKIN) - channel_fail_forget(channel, "%s: %s ERROR %s", + channel_fail_forget(channel, "%s: %s %s", channel->owner->name, err_for_them ? "sent" : "received", desc); else channel_fail_permanent(channel, err_for_them ? REASON_LOCAL : REASON_PROTOCOL, - "%s: %s ERROR %s", + "%s: %s %s", channel->owner->name, err_for_them ? "sent" : "received", desc); } diff --git a/openingd/dualopend.c b/openingd/dualopend.c index d8b0f494b..d3ca9aeac 100644 --- a/openingd/dualopend.c +++ b/openingd/dualopend.c @@ -331,8 +331,7 @@ static void negotiation_aborted(struct state *state, const char *why, bool abort status_debug("aborted opening negotiation: %s", why); /* Tell master that funding failed. */ - peer_failed_received_errmsg(state->pps, why, - &state->channel_id, true, aborted); + peer_failed_received_errmsg(state->pps, why, aborted); } /* Softer version of 'warning' (we don't disconnect) @@ -1289,8 +1288,7 @@ static u8 *opening_negotiate_msg(const tal_t *ctx, struct state *state) * form, but we use it in a very limited way. */ for (;;) { u8 *msg; - char *err; - bool warning; + const char *err; enum peer_wire t; /* The event loop is responsible for freeing tmpctx, so our @@ -1310,24 +1308,20 @@ static u8 *opening_negotiate_msg(const tal_t *ctx, struct state *state) continue; /* A helper which decodes an error. */ - if (is_peer_error(tmpctx, msg, &state->channel_id, - &err, &warning)) { - /* BOLT #1: - * - * - if no existing channel is referred to by `channel_id`: - * - MUST ignore the message. - */ - /* In this case, is_peer_error returns true, but sets - * err to NULL */ - if (!err) { - tal_free(msg); - continue; - } + err = is_peer_error(tmpctx, msg); + if (err) { negotiation_aborted(state, tal_fmt(tmpctx, "They sent %s", err), false); /* Return NULL so caller knows to stop negotiating. */ - return NULL; + return tal_free(msg); + } + + err = is_peer_warning(tmpctx, msg); + if (err) { + status_info("They sent %s", err); + tal_free(msg); + continue; } /* In theory, we're in the middle of an open/RBF, but @@ -3973,9 +3967,7 @@ static void do_reconnect_dance(struct state *state) do { clean_tmpctx(); msg = peer_read(tmpctx, state->pps); - } while (handle_peer_error(state->pps, - &state->channel_id, - msg)); + } while (handle_peer_error_or_warning(state->pps, msg)); if (!fromwire_channel_reestablish(tmpctx, msg, &cid, &next_commitment_number, @@ -4185,7 +4177,7 @@ static u8 *handle_peer_in(struct state *state) } /* Handles errors. */ - if (handle_peer_error(state->pps, &state->channel_id, msg)) + if (handle_peer_error_or_warning(state->pps, msg)) return NULL; peer_write(state->pps, diff --git a/openingd/openingd.c b/openingd/openingd.c index 2958a6c1f..82af17d35 100644 --- a/openingd/openingd.c +++ b/openingd/openingd.c @@ -185,8 +185,7 @@ static u8 *opening_negotiate_msg(const tal_t *ctx, struct state *state, * form, but we use it in a very limited way. */ for (;;) { u8 *msg; - char *err; - bool warning; + const char *err; /* The event loop is responsible for freeing tmpctx, so our * temporary allocations don't grow unbounded. */ @@ -205,24 +204,20 @@ static u8 *opening_negotiate_msg(const tal_t *ctx, struct state *state, continue; /* A helper which decodes an error. */ - if (is_peer_error(tmpctx, msg, &state->channel_id, - &err, &warning)) { - /* BOLT #1: - * - * - if no existing channel is referred to by `channel_id`: - * - MUST ignore the message. - */ - /* In this case, is_peer_error returns true, but sets - * err to NULL */ - if (!err) { - tal_free(msg); - continue; - } + err = is_peer_error(tmpctx, msg); + if (err) { negotiation_aborted(state, tal_fmt(tmpctx, "They sent %s", err)); /* Return NULL so caller knows to stop negotiating. */ - return NULL; + return tal_free(msg); + } + + err = is_peer_warning(tmpctx, msg); + if (err) { + status_info("They sent %s", err); + tal_free(msg); + continue; } /* If we get here, it's an interesting message. */ @@ -1391,7 +1386,7 @@ static u8 *handle_peer_in(struct state *state) return fundee_channel(state, msg); /* Handles error cases. */ - if (handle_peer_error(state->pps, &state->channel_id, msg)) + if (handle_peer_error_or_warning(state->pps, msg)) return NULL; extracted = extract_channel_id(msg, &channel_id); diff --git a/tests/test_connection.py b/tests/test_connection.py index f847a6e93..ddf394607 100644 --- a/tests/test_connection.py +++ b/tests/test_connection.py @@ -413,7 +413,7 @@ def test_opening_tiny_channel(node_factory, anchors): l1.rpc.connect(l3.info['id'], 'localhost', l3.port) l1.rpc.connect(l4.info['id'], 'localhost', l4.port) - with pytest.raises(RpcError, match=r'They sent [error|warning].*channel capacity is .*, which is below .*sat'): + with pytest.raises(RpcError, match=r'They sent (ERROR|WARNING).*channel capacity is .*, which is below .*sat'): l1.fundchannel(l2, l2_min_capacity + overhead - 1) if EXPERIMENTAL_DUAL_FUND: assert only_one(l1.rpc.listpeers(l2.info['id'])['peers'])['connected'] @@ -422,7 +422,7 @@ def test_opening_tiny_channel(node_factory, anchors): l1.rpc.connect(l2.info['id'], 'localhost', l2.port) l1.fundchannel(l2, l2_min_capacity + overhead) - with pytest.raises(RpcError, match=r'They sent [error|warning].*channel capacity is .*, which is below .*sat'): + with pytest.raises(RpcError, match=r'They sent (ERROR|WARNING).*channel capacity is .*, which is below .*sat'): l1.fundchannel(l3, l3_min_capacity + overhead - 1) if EXPERIMENTAL_DUAL_FUND: assert only_one(l1.rpc.listpeers(l3.info['id'])['peers'])['connected'] @@ -431,7 +431,7 @@ def test_opening_tiny_channel(node_factory, anchors): l1.rpc.connect(l3.info['id'], 'localhost', l3.port) l1.fundchannel(l3, l3_min_capacity + overhead) - with pytest.raises(RpcError, match=r'They sent [error|warning].*channel capacity is .*, which is below .*sat'): + with pytest.raises(RpcError, match=r'They sent (ERROR|WARNING).*channel capacity is .*, which is below .*sat'): l1.fundchannel(l4, l4_min_capacity + overhead - 1) if EXPERIMENTAL_DUAL_FUND: assert only_one(l1.rpc.listpeers(l4.info['id'])['peers'])['connected'] @@ -2510,10 +2510,13 @@ def test_fee_limits(node_factory, bitcoind): l1.set_feerates((15, 15, 15, 15), False) l1.start() - l1.daemon.wait_for_log('Peer transient failure in CHANNELD_NORMAL: channeld WARNING: .*: update_fee 253 outside range 1875-75000') + l1.daemon.wait_for_log('Received WARNING .*: update_fee 253 outside range 1875-75000') + # They hang up on *us* + l1.daemon.wait_for_log('Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died') - # Closes, but does not error. Make sure it's noted in their status though. - assert 'update_fee 253 outside range 1875-75000' in only_one(l1.rpc.listpeerchannels(l2.info['id'])['channels'])['status'][0] + # Disconnects, but does not error. Make sure it's noted in their status though. + # FIXME: does not happen for l1! + # assert 'update_fee 253 outside range 1875-75000' in only_one(l1.rpc.listpeerchannels(l2.info['id'])['channels'])['status'][0] assert 'update_fee 253 outside range 1875-75000' in only_one(l2.rpc.listpeerchannels(l1.info['id'])['channels'])['status'][0] assert only_one(l2.rpc.listpeerchannels()['channels'])['feerate']['perkw'] != 253 @@ -2536,7 +2539,7 @@ def test_fee_limits(node_factory, bitcoind): # Trying to open a channel with too low a fee-rate is denied l1.rpc.connect(l4.info['id'], 'localhost', l4.port) - with pytest.raises(RpcError, match='They sent error .* feerate_per_kw 253 below minimum'): + with pytest.raises(RpcError, match='They sent (ERROR|WARNING) .* feerate_per_kw 253 below minimum'): l1.fundchannel(l4, 10**6) # Restore to normal. diff --git a/tests/test_misc.py b/tests/test_misc.py index ee59d5b7f..020a96d15 100644 --- a/tests/test_misc.py +++ b/tests/test_misc.py @@ -1333,7 +1333,7 @@ def test_funding_reorg_remote_lags(node_factory, bitcoind): bitcoind.generate_block(1) l1.daemon.wait_for_log(r'Peer transient failure .* short_channel_id changed to 104x1x0 \(was 103x1x0\)') - l2.daemon.wait_for_logs([r'Peer transient failure in CHANNELD_NORMAL: channeld WARNING: Bad node_signature*']) + l2.daemon.wait_for_logs([r'Peer transient failure in CHANNELD_NORMAL: channeld sent Bad node_signature*']) # Unblinding l2 brings it back in sync, restarts channeld and sends its announce sig l2.daemon.rpcproxy.mock_rpc('getblockhash', None) diff --git a/tests/test_pay.py b/tests/test_pay.py index a936ce151..f7ce7a2fa 100644 --- a/tests/test_pay.py +++ b/tests/test_pay.py @@ -284,7 +284,9 @@ def test_pay_disconnect(node_factory, bitcoind): l1.set_feerates((10**6, 10**6, 10**6, 10**6), False) # Wait for l1 notice - l1.daemon.wait_for_log(r'Peer transient failure in CHANNELD_NORMAL: channeld WARNING: .*: update_fee \d+ outside range 1875-75000') + l1.daemon.wait_for_log(r'WARNING .*: update_fee \d+ outside range 1875-75000') + # They hang up on us + l1.daemon.wait_for_log(r'Peer transient failure in CHANNELD_NORMAL') # Make l2 fail hard. l2.rpc.close(l1.info['id'], unilateraltimeout=1) diff --git a/tests/test_plugin.py b/tests/test_plugin.py index 52d246bc2..465a1c560 100644 --- a/tests/test_plugin.py +++ b/tests/test_plugin.py @@ -993,7 +993,7 @@ def test_channel_state_changed_unilateral(node_factory, bitcoind): assert(event1['old_state'] == "CHANNELD_NORMAL") assert(event1['new_state'] == "AWAITING_UNILATERAL") assert(event1['cause'] == "protocol") - assert(event1['message'] == "channeld: received ERROR error channel {}: Forcibly closed by `close` command timeout".format(cid)) + assert(event1['message'] == "channeld: received ERROR channel {}: Forcibly closed by `close` command timeout".format(cid)) # settle the channel closure bitcoind.generate_block(100)