From fd498be7ca6a0ab5281350f31fc4946553382258 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Thu, 8 Feb 2018 11:55:12 +1030 Subject: [PATCH] status: generate messages rather than marshal/unmarshal manually. Now we have wirestring, this is much more natural. And with the 24M length limit, we needn't be so concerned about dumping 64k peer messages in hex. Signed-off-by: Rusty Russell --- channeld/Makefile | 2 + closingd/Makefile | 2 + common/Makefile | 23 +++++++++--- common/status.c | 52 ++++++-------------------- common/status.h | 3 +- common/status_levels.h | 14 ++----- common/status_wire.c | 33 ++++++++++++++++ common/status_wire.csv | 14 +++++++ common/status_wire.h | 14 +++++++ gossipd/Makefile | 2 + gossipd/test/run-bench-find_route.c | 3 +- gossipd/test/run-find_route-specific.c | 3 +- gossipd/test/run-find_route.c | 3 +- hsmd/Makefile | 2 + lightningd/Makefile | 2 + lightningd/log_status.c | 32 +++++++--------- lightningd/subd.c | 50 +++++++++---------------- onchaind/Makefile | 2 + openingd/Makefile | 2 + 19 files changed, 147 insertions(+), 111 deletions(-) create mode 100644 common/status_wire.c create mode 100644 common/status_wire.csv create mode 100644 common/status_wire.h diff --git a/channeld/Makefile b/channeld/Makefile index 4e63435af..bcccc4604 100644 --- a/channeld/Makefile +++ b/channeld/Makefile @@ -40,6 +40,7 @@ CHANNELD_COMMON_OBJS := \ common/daemon_conn.o \ common/derive_basepoints.o \ common/dev_disconnect.o \ + common/gen_status_wire.o \ common/htlc_state.o \ common/htlc_tx.o \ common/htlc_wire.o \ @@ -57,6 +58,7 @@ CHANNELD_COMMON_OBJS := \ common/read_peer_msg.o \ common/sphinx.o \ common/status.o \ + common/status_wire.o \ common/subdaemon.o \ common/timeout.o \ common/type_to_string.o \ diff --git a/closingd/Makefile b/closingd/Makefile index 54bd5e066..a1e7184d9 100644 --- a/closingd/Makefile +++ b/closingd/Makefile @@ -49,6 +49,7 @@ CLOSINGD_COMMON_OBJS := \ common/daemon_conn.o \ common/dev_disconnect.o \ common/derive_basepoints.o \ + common/gen_status_wire.o \ common/htlc_wire.o \ common/memleak.o \ common/msg_queue.o \ @@ -57,6 +58,7 @@ CLOSINGD_COMMON_OBJS := \ common/ping.o \ common/read_peer_msg.o \ common/status.o \ + common/status_wire.o \ common/subdaemon.o \ common/type_to_string.o \ common/utils.o \ diff --git a/common/Makefile b/common/Makefile index b252a5242..141043add 100644 --- a/common/Makefile +++ b/common/Makefile @@ -1,4 +1,4 @@ -COMMON_SRC := \ +COMMON_SRC_NOGEN := \ common/bech32.c \ common/bip32.c \ common/bolt11.c \ @@ -32,6 +32,7 @@ COMMON_SRC := \ common/read_peer_msg.c \ common/sphinx.c \ common/status.c \ + common/status_wire.c \ common/subdaemon.c \ common/timeout.c \ common/type_to_string.c \ @@ -42,10 +43,14 @@ COMMON_SRC := \ common/wire_error.c \ common/withdraw_tx.c -COMMON_HEADERS_NOGEN := $(COMMON_SRC:.c=.h) common/overflows.h common/htlc.h common/status_levels.h -COMMON_HEADERS_GEN := common/gen_htlc_state_names.h +COMMON_SRC_GEN := common/gen_status_wire.c + +COMMON_HEADERS_NOGEN := $(COMMON_SRC_NOGEN:.c=.h) common/overflows.h common/htlc.h common/status_levels.h +COMMON_HEADERS_GEN := common/gen_htlc_state_names.h common/gen_status_wire.h COMMON_HEADERS := $(COMMON_HEADERS_GEN) $(COMMON_HEADERS_NOGEN) +COMMON_SRC := $(COMMON_SRC_NOGEN) $(COMMON_SRC_GEN) + COMMON_OBJS := $(COMMON_SRC:.c=.o) # Common objects depends on bitcoin/ external/ and ccan @@ -57,15 +62,21 @@ ALL_OBJS += $(COMMON_OBJS) common/gen_htlc_state_names.h: common/htlc_state.h ccan/ccan/cdump/tools/cdump-enumstr ccan/ccan/cdump/tools/cdump-enumstr common/htlc_state.h > $@ +common/gen_status_wire.h: $(WIRE_GEN) common/status_wire.csv + $(WIRE_GEN) --header $@ status < common/status_wire.csv > $@ + +common/gen_status_wire.c: $(WIRE_GEN) common/status_wire.csv + $(WIRE_GEN) ${@:.c=.h} status < common/status_wire.csv > $@ + check-makefile: check-common-makefile check-common-makefile: if [ x"`LC_ALL=C ls common/*.h | grep -v ^common/gen_`" != x"`echo $(COMMON_HEADERS_NOGEN) | tr ' ' '\n' | LC_ALL=C sort`" ]; then echo COMMON_HEADERS_NOGEN incorrect; exit 1; fi -check-source-bolt: $(COMMON_SRC:%=bolt-check/%) $(COMMON_HEADERS:%=bolt-check/%) -check-whitespace: $(COMMON_SRC:%=check-whitespace/%) $(COMMON_HEADERS:%=check-whitespace/%) +check-source-bolt: $(COMMON_SRC_NOGEN:%=bolt-check/%) $(COMMON_HEADERS:%=bolt-check/%) +check-whitespace: $(COMMON_SRC_NOGEN:%=check-whitespace/%) $(COMMON_HEADERS:%=check-whitespace/%) -check-source: $(COMMON_SRC:%=check-src-include-order/%) \ +check-source: $(COMMON_SRC_NOGEN:%=check-src-include-order/%) \ $(COMMON_HEADERS_NOGEN:%=check-hdr-include-order/%) clean: common-clean diff --git a/common/status.c b/common/status.c index 686031a66..7602c2b80 100644 --- a/common/status.c +++ b/common/status.c @@ -7,6 +7,7 @@ #include #include #include +#include #include #include #include @@ -56,50 +57,20 @@ void status_setup_async(struct daemon_conn *master) setup_logging_sighandler(); } -static bool too_large(size_t len, int type) +static void status_send(const u8 *msg TAKES) { - if (len > 65535) { - status_trace("About to truncate msg %i from %zu bytes", - type, len); - return true; - } - return false; -} - -static void status_send_with_hdr(u16 type, const void *p, size_t len) -{ - u8 *msg = tal_arr(NULL, u8, 0); - towire_u16(&msg, type); - towire(&msg, p, len); - if (too_large(tal_len(msg), type)) - tal_resize(&msg, 65535); - if (status_fd >= 0) { - if (!wire_sync_write(status_fd, take(msg))) - err(1, "Writing out status %u len %zu", type, len); + int type =fromwire_peektype(msg); + if (!wire_sync_write(status_fd, msg)) + err(1, "Writing out status %i", type); } else { - daemon_conn_send(status_conn, take(msg)); + daemon_conn_send(status_conn, msg); } } static void status_io_full(enum log_level iodir, const u8 *p) { - u16 type = STATUS_LOG_MIN + iodir; - u8 *msg = tal_arr(NULL, u8, 0); - - assert(iodir == LOG_IO_IN || iodir == LOG_IO_OUT); - towire_u16(&msg, type); - towire(&msg, p, tal_len(p)); - if (too_large(tal_len(msg), type)) - tal_resize(&msg, 65535); - - if (status_fd >= 0) { - if (!wire_sync_write(status_fd, take(msg))) - err(1, "Writing out status %u len %zu", - type, tal_len(p)); - } else { - daemon_conn_send(status_conn, take(msg)); - } + status_send(take(towire_status_io(NULL, iodir, p))); } static void status_io_short(enum log_level iodir, const u8 *p) @@ -122,7 +93,7 @@ void status_vfmt(enum log_level level, const char *fmt, va_list ap) char *str; str = tal_vfmt(NULL, fmt, ap); - status_send_with_hdr(STATUS_LOG_MIN + level, str, strlen(str)); + status_send(take(towire_status_log(NULL, level, str))); tal_free(str); /* Free up any temporary children. */ @@ -141,16 +112,15 @@ void status_fmt(enum log_level level, const char *fmt, ...) va_end(ap); } -void status_failed(enum status_fail code, const char *fmt, ...) +void status_failed(enum status_failreason reason, const char *fmt, ...) { va_list ap; char *str; breakpoint(); - assert(code & STATUS_FAIL); va_start(ap, fmt); str = tal_vfmt(NULL, fmt, ap); - status_send_with_hdr(code, str, strlen(str)); + status_send(take(towire_status_fail(NULL, reason, str))); va_end(ap); /* Don't let it take forever. */ @@ -158,7 +128,7 @@ void status_failed(enum status_fail code, const char *fmt, ...) if (status_conn) daemon_conn_sync_flush(status_conn); - exit(0x80 | (code & 0xFF)); + exit(0x80 | (reason & 0xFF)); } void master_badmsg(u32 type_expected, const u8 *msg) diff --git a/common/status.h b/common/status.h index 8ba0a4369..6782edb84 100644 --- a/common/status.h +++ b/common/status.h @@ -43,7 +43,8 @@ void status_io(enum log_level iodir, const u8 *p); #define status_trace(...) status_debug(__VA_ARGS__) /* Send a failure status code with printf-style msg, and exit. */ -void status_failed(enum status_fail code, const char *fmt, ...) PRINTF_FMT(2,3) NORETURN; +void status_failed(enum status_failreason code, + const char *fmt, ...) PRINTF_FMT(2,3) NORETURN; /* Helper for master failures: sends STATUS_FAIL_MASTER_IO. * msg NULL == read failure. */ diff --git a/common/status_levels.h b/common/status_levels.h index 456030723..298f02720 100644 --- a/common/status_levels.h +++ b/common/status_levels.h @@ -15,21 +15,14 @@ enum log_level { /* That's really bad, we're broken. */ LOG_BROKEN }; +#define LOG_LEVEL_MAX LOG_BROKEN -/* Special status code for tracing messages (subtract log_level). */ -#define STATUS_LOG_MIN (STATUS_LOG_MAX - LOG_BROKEN) -#define STATUS_LOG_MAX (0x7FFF) - -/* Failure codes always have high bit set. */ -#define STATUS_FAIL 0x8000 - -/* These are always followed by an ASCII string. */ -enum status_fail { +enum status_failreason { /* * These errors shouldn't happen: */ /* Master daemon sent unknown/malformed command, or fd failed */ - STATUS_FAIL_MASTER_IO = STATUS_FAIL, + STATUS_FAIL_MASTER_IO, /* Hsmd sent unknown/malformed command, or fd failed */ STATUS_FAIL_HSM_IO, @@ -49,5 +42,6 @@ enum status_fail { /* Peer did something else wrong */ STATUS_FAIL_PEER_BAD }; +#define STATUS_FAIL_MAX STATUS_FAIL_PEER_BAD #endif /* LIGHTNING_COMMON_STATUS_LEVELS_H */ diff --git a/common/status_wire.c b/common/status_wire.c new file mode 100644 index 000000000..25afd376b --- /dev/null +++ b/common/status_wire.c @@ -0,0 +1,33 @@ +#include +#include + +enum status_failreason fromwire_status_failreason(const u8 **cursor, + size_t *max) +{ + u8 r = fromwire_u8(cursor, max); + if (r > STATUS_FAIL_MAX) { + fromwire_fail(cursor, max); + r = STATUS_FAIL_INTERNAL_ERROR; + } + return r; +} + +enum log_level fromwire_log_level(const u8 **cursor, size_t *max) +{ + u8 l = fromwire_u8(cursor, max); + if (l > LOG_LEVEL_MAX) { + fromwire_fail(cursor, max); + l = LOG_BROKEN; + } + return l; +} + +void towire_log_level(u8 **pptr, enum log_level level) +{ + towire_u8(pptr, level); +} + +void towire_status_failreason(u8 **pptr, enum status_failreason reason) +{ + towire_u8(pptr, reason); +} diff --git a/common/status_wire.csv b/common/status_wire.csv new file mode 100644 index 000000000..b7619b3bd --- /dev/null +++ b/common/status_wire.csv @@ -0,0 +1,14 @@ +#include + +status_log,0xFFF0 +status_log,,level,enum log_level +status_log,,entry,wirestring + +status_io,0xFFF1 +status_io,,iodir,enum log_level +status_io,,len,u16 +status_io,,data,len*u8 + +status_fail,0xFFF2 +status_fail,,failreason,enum status_failreason +status_fail,,desc,wirestring diff --git a/common/status_wire.h b/common/status_wire.h new file mode 100644 index 000000000..e2c7305c6 --- /dev/null +++ b/common/status_wire.h @@ -0,0 +1,14 @@ +#ifndef LIGHTNING_COMMON_STATUS_WIRE_H +#define LIGHTNING_COMMON_STATUS_WIRE_H +#include "config.h" +#include +#include +#include + +enum status_failreason fromwire_status_failreason(const u8 **cursor, + size_t *max); +enum log_level fromwire_log_level(const u8 **cursor, size_t *max); + +void towire_log_level(u8 **pptr, enum log_level level); +void towire_status_failreason(u8 **pptr, enum status_failreason reason); +#endif /* LIGHTNING_COMMON_STATUS_WIRE_H */ diff --git a/gossipd/Makefile b/gossipd/Makefile index 0a8b3f93f..32fd30e49 100644 --- a/gossipd/Makefile +++ b/gossipd/Makefile @@ -41,11 +41,13 @@ GOSSIPD_COMMON_OBJS := \ common/daemon_conn.o \ common/dev_disconnect.o \ common/features.o \ + common/gen_status_wire.o \ common/io_debug.o \ common/msg_queue.o \ common/ping.o \ common/pseudorand.o \ common/status.o \ + common/status_wire.o \ common/subdaemon.o \ common/timeout.o \ common/type_to_string.o \ diff --git a/gossipd/test/run-bench-find_route.c b/gossipd/test/run-bench-find_route.c index effe8e5dc..6c0999a39 100644 --- a/gossipd/test/run-bench-find_route.c +++ b/gossipd/test/run-bench-find_route.c @@ -90,7 +90,8 @@ bool replace_broadcast(struct broadcast_state *bstate UNNEEDED, const u8 *payload UNNEEDED) { fprintf(stderr, "replace_broadcast called!\n"); abort(); } /* Generated stub for status_failed */ -void status_failed(enum status_fail code UNNEEDED, const char *fmt UNNEEDED, ...) +void status_failed(enum status_failreason code UNNEEDED, + const char *fmt UNNEEDED, ...) { fprintf(stderr, "status_failed called!\n"); abort(); } /* Generated stub for towire_pubkey */ void towire_pubkey(u8 **pptr UNNEEDED, const struct pubkey *pubkey UNNEEDED) diff --git a/gossipd/test/run-find_route-specific.c b/gossipd/test/run-find_route-specific.c index 117d38743..accc20f8f 100644 --- a/gossipd/test/run-find_route-specific.c +++ b/gossipd/test/run-find_route-specific.c @@ -54,7 +54,8 @@ bool replace_broadcast(struct broadcast_state *bstate UNNEEDED, const u8 *payload UNNEEDED) { fprintf(stderr, "replace_broadcast called!\n"); abort(); } /* Generated stub for status_failed */ -void status_failed(enum status_fail code UNNEEDED, const char *fmt UNNEEDED, ...) +void status_failed(enum status_failreason code UNNEEDED, + const char *fmt UNNEEDED, ...) { fprintf(stderr, "status_failed called!\n"); abort(); } /* Generated stub for towire_pubkey */ void towire_pubkey(u8 **pptr UNNEEDED, const struct pubkey *pubkey UNNEEDED) diff --git a/gossipd/test/run-find_route.c b/gossipd/test/run-find_route.c index 428693705..f6f60e473 100644 --- a/gossipd/test/run-find_route.c +++ b/gossipd/test/run-find_route.c @@ -52,7 +52,8 @@ bool replace_broadcast(struct broadcast_state *bstate UNNEEDED, const u8 *payload UNNEEDED) { fprintf(stderr, "replace_broadcast called!\n"); abort(); } /* Generated stub for status_failed */ -void status_failed(enum status_fail code UNNEEDED, const char *fmt UNNEEDED, ...) +void status_failed(enum status_failreason code UNNEEDED, + const char *fmt UNNEEDED, ...) { fprintf(stderr, "status_failed called!\n"); abort(); } /* Generated stub for towire_pubkey */ void towire_pubkey(u8 **pptr UNNEEDED, const struct pubkey *pubkey UNNEEDED) diff --git a/hsmd/Makefile b/hsmd/Makefile index 7f27b23d5..dfca17f2f 100644 --- a/hsmd/Makefile +++ b/hsmd/Makefile @@ -24,12 +24,14 @@ HSMD_COMMON_OBJS := \ common/daemon_conn.o \ common/derive_basepoints.o \ common/funding_tx.o \ + common/gen_status_wire.o \ common/hash_u5.o \ common/io_debug.o \ common/key_derive.o \ common/msg_queue.o \ common/permute_tx.o \ common/status.o \ + common/status_wire.o \ common/subdaemon.o \ common/type_to_string.o \ common/utils.o \ diff --git a/lightningd/Makefile b/lightningd/Makefile index 2981d8349..6c6bb4bf3 100644 --- a/lightningd/Makefile +++ b/lightningd/Makefile @@ -23,6 +23,7 @@ LIGHTNINGD_COMMON_OBJS := \ common/derive_basepoints.o \ common/features.o \ common/funding_tx.o \ + common/gen_status_wire.o \ common/hash_u5.o \ common/htlc_state.o \ common/htlc_wire.o \ @@ -34,6 +35,7 @@ LIGHTNINGD_COMMON_OBJS := \ common/permute_tx.o \ common/pseudorand.o \ common/sphinx.o \ + common/status_wire.o \ common/timeout.o \ common/type_to_string.o \ common/utils.o \ diff --git a/lightningd/log_status.c b/lightningd/log_status.c index adb9fa6d2..b3181195c 100644 --- a/lightningd/log_status.c +++ b/lightningd/log_status.c @@ -1,26 +1,22 @@ +#include #include -#include bool log_status_msg(struct log *log, const u8 *msg) { - size_t max = tal_len(msg); - int type = fromwire_u16(&msg, &max); - enum log_level level; + char *entry; + u8 *data; + enum log_level level; - if (type < STATUS_LOG_MIN || type > STATUS_LOG_MAX) - return false; - - level = type - STATUS_LOG_MIN; - if (level == LOG_IO_IN || level == LOG_IO_OUT) { - log_io(log, level, "", msg, max); - } else { - int i; - /* Truncate if unprintable */ - for (i = 0; i < max; i++) { - if (!cisprint((char)msg[i])) - break; + if (fromwire_status_log(msg, msg, NULL, &level, &entry)) { + if (level != LOG_IO_IN && level != LOG_IO_OUT) { + log_(log, level, "%s", entry); + return true; + } + } else if (fromwire_status_io(msg, msg, NULL, &level, &data)) { + if (level == LOG_IO_IN || level == LOG_IO_OUT) { + log_io(log, level, "", data, tal_len(data)); + return true; } - log_(log, level, "%.*s%s", i, msg, i == max ? "" : "..."); } - return true; + return false; } diff --git a/lightningd/subd.c b/lightningd/subd.c index bb075a41d..652b3fc40 100644 --- a/lightningd/subd.c +++ b/lightningd/subd.c @@ -7,6 +7,7 @@ #include #include #include +#include #include #include #include @@ -337,24 +338,9 @@ static struct io_plan *sd_collect_fds(struct io_conn *conn, struct subd *sd, return read_fds(conn, sd); } -/* Don't trust, verify. Returns NULL if contains weird stuff. */ -static const char *string_from_msg(const u8 *msg, int *str_len) -{ - size_t len = tal_count(msg) - sizeof(be16), i; - - for (i = 0; i < len; i++) { - if (!cisprint((char)msg[sizeof(be16) + i])) { - *str_len = 0; - return NULL; - } - } - *str_len = len; - return (const char *)(msg + sizeof(be16)); -} - static void subdaemon_malformed_msg(struct subd *sd, const u8 *msg) { - log_broken(sd->log, "%i: malformed string '%.s'", + log_broken(sd->log, "%i: malformed message '%.s'", fromwire_peektype(msg), tal_hex(msg, msg)); @@ -364,9 +350,8 @@ static void subdaemon_malformed_msg(struct subd *sd, const u8 *msg) #endif } -/* Returns true if logged, false if malformed. */ -static bool log_status_fail(struct subd *sd, - enum status_fail type, const char *str, int str_len) +static void log_status_fail(struct subd *sd, + enum status_failreason type, const char *str) { const char *name; @@ -394,23 +379,24 @@ static bool log_status_fail(struct subd *sd, name = "STATUS_FAIL_PEER_BAD"; goto log_str_peer; } - return false; + /* fromwire_status_fail() guarantees it's one of those... */ + abort(); /* Peers misbehaving is expected. */ log_str_peer: - log_info(sd->log, "%s: %.*s", name, str_len, str); - return true; + log_info(sd->log, "%s: %s", name, str); + return; /* Shouldn't happen. */ log_str_broken: - log_broken(sd->log, "%s: %.*s", name, str_len, str); + log_broken(sd->log, "%s: %s", name, str); #if DEVELOPER if (sd->ld->dev_subdaemon_fail) fatal("Subdaemon %s hit error", sd->name); #endif - return true; + return; } static struct io_plan *sd_msg_read(struct io_conn *conn, struct subd *sd) @@ -447,22 +433,22 @@ static struct io_plan *sd_msg_read(struct io_conn *conn, struct subd *sd) if (log_status_msg(sd->log, sd->msg_in)) goto next; - if (type & STATUS_FAIL) { - int str_len; - const char *str = string_from_msg(sd->msg_in, &str_len); - if (!str) + if (type == WIRE_STATUS_FAIL) { + enum status_failreason failreason; + char *desc; + if (!fromwire_status_fail(sd->msg_in, sd->msg_in, NULL, + &failreason, &desc)) goto malformed; - if (!log_status_fail(sd, type, str, str_len)) - goto malformed; + log_status_fail(sd, failreason, desc); /* If they care, tell them about invalid peer behavior */ - if (sd->peer && type == STATUS_FAIL_PEER_BAD) { + if (sd->peer && failreason == STATUS_FAIL_PEER_BAD) { /* Don't free ourselves; we're about to do that. */ struct peer *peer = sd->peer; sd->peer = NULL; - peer_fail_permanent(peer, "%s: %.*s", sd->name, str_len, str); + peer_fail_permanent(peer, "%s: %s", sd->name, desc); } goto close; } diff --git a/onchaind/Makefile b/onchaind/Makefile index 8b89bfb1d..b1adbabbf 100644 --- a/onchaind/Makefile +++ b/onchaind/Makefile @@ -50,6 +50,7 @@ ONCHAIND_COMMON_OBJS := \ common/daemon_conn.o \ common/derive_basepoints.o \ common/dev_disconnect.o \ + common/gen_status_wire.o \ common/htlc_tx.o \ common/htlc_wire.o \ common/initial_commit_tx.o \ @@ -59,6 +60,7 @@ ONCHAIND_COMMON_OBJS := \ common/msg_queue.o \ common/permute_tx.o \ common/status.o \ + common/status_wire.o \ common/subdaemon.o \ common/type_to_string.o \ common/utils.o \ diff --git a/openingd/Makefile b/openingd/Makefile index bb7b36881..f74ed4219 100644 --- a/openingd/Makefile +++ b/openingd/Makefile @@ -44,6 +44,7 @@ OPENINGD_COMMON_OBJS := \ common/derive_basepoints.o \ common/dev_disconnect.o \ common/funding_tx.o \ + common/gen_status_wire.o \ common/htlc_wire.o \ common/initial_channel.o \ common/initial_commit_tx.o \ @@ -57,6 +58,7 @@ OPENINGD_COMMON_OBJS := \ common/pseudorand.o \ common/read_peer_msg.o \ common/status.o \ + common/status_wire.o \ common/subdaemon.o \ common/type_to_string.o \ common/utils.o \