diff --git a/CHANGELOG.md b/CHANGELOG.md index 23d857406136..bfd6faeebeaf 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -24,6 +24,7 @@ changes. ### Fixed - `--bind-addr=` fixed for nodes using local sockets (eg. testing). +- Unannounced local channels were forgotten for routing on restart until reconnection occurred. ### Security diff --git a/common/daemon.c b/common/daemon.c index cf8f46ae96e3..fc93c1793ce7 100644 --- a/common/daemon.c +++ b/common/daemon.c @@ -32,17 +32,25 @@ static int backtrace_status(void *unused UNUSED, uintptr_t pc, return 0; } -static void crashdump(int sig) +void send_backtrace(const char *why) { /* We do stderr first, since it's most reliable. */ - warnx("Fatal signal %d (version %s)", sig, version()); + warnx("%s (version %s)", why, version()); if (backtrace_state) backtrace_print(backtrace_state, 0, stderr); /* Now send to parent. */ - bt_print("FATAL SIGNAL %d (version %s)", sig, version()); + bt_print("%s (version %s)", why, version()); if (backtrace_state) backtrace_full(backtrace_state, 0, backtrace_status, NULL, NULL); +} + +static void crashdump(int sig) +{ + char why[100]; + + snprintf(why, 100, "FATAL SIGNAL %d", sig); + send_backtrace(why); /* Probably shouldn't return. */ bt_exit(); @@ -66,6 +74,10 @@ static void crashlog_activate(void) sigaction(SIGSEGV, &sa, NULL); sigaction(SIGBUS, &sa, NULL); } +#else +void send_backtrace(const char *why) +{ +} #endif int daemon_poll(struct pollfd *fds, nfds_t nfds, int timeout) diff --git a/common/daemon.h b/common/daemon.h index 5a0a01fb0b0f..3fbfb570a949 100644 --- a/common/daemon.h +++ b/common/daemon.h @@ -11,6 +11,9 @@ void daemon_setup(const char *argv0, /* Exposed for lightningd's use. */ int daemon_poll(struct pollfd *fds, nfds_t nfds, int timeout); +/* Print a backtrace to stderr, and via backtrace_print */ +void send_backtrace(const char *why); + /* Shutdown for a valgrind-clean exit (frees everything) */ void daemon_shutdown(void); diff --git a/common/status.c b/common/status.c index 3eef72264409..9c59cf336918 100644 --- a/common/status.c +++ b/common/status.c @@ -5,6 +5,7 @@ #include #include #include +#include #include #include #include @@ -167,6 +168,10 @@ void status_failed(enum status_failreason reason, const char *fmt, ...) str = tal_vfmt(NULL, fmt, ap); va_end(ap); + /* Give a nice backtrace when this happens! */ + if (reason == STATUS_FAIL_INTERNAL_ERROR) + send_backtrace(str); + status_send_fatal(take(towire_status_fail(NULL, reason, str)), -1, -1); } diff --git a/devtools/Makefile b/devtools/Makefile index 8018804b8692..73353619c89f 100644 --- a/devtools/Makefile +++ b/devtools/Makefile @@ -1,6 +1,6 @@ DEVTOOLS_SRC := devtools/gen_print_wire.c devtools/gen_print_onion_wire.c devtools/print_wire.c DEVTOOLS_OBJS := $(DEVTOOLS_SRC:.c=.o) -DEVTOOLS := devtools/bolt11-cli devtools/decodemsg devtools/onion devtools/dump-gossipstore devtools/gossipwith +DEVTOOLS := devtools/bolt11-cli devtools/decodemsg devtools/onion devtools/dump-gossipstore devtools/gossipwith devtools/create-gossipstore DEVTOOLS_TOOL_SRC := $(DEVTOOLS:=.c) DEVTOOLS_TOOL_OBJS := $(DEVTOOLS_TOOL_SRC:.c=.o) @@ -16,7 +16,8 @@ DEVTOOLS_COMMON_OBJS := \ common/utils.o \ common/version.o \ common/wireaddr.o \ - wire/gen_onion_wire.o + wire/gen_onion_wire.o \ + wire/gen_peer_wire.o devtools-all: $(DEVTOOLS) @@ -39,6 +40,10 @@ devtools/decodemsg: $(DEVTOOLS_OBJS) $(DEVTOOLS_COMMON_OBJS) $(JSMN_OBJS) $(CCAN devtools/dump-gossipstore: $(DEVTOOLS_OBJS) $(DEVTOOLS_COMMON_OBJS) $(JSMN_OBJS) $(CCAN_OBJS) $(BITCOIN_OBJS) wire/fromwire.o wire/towire.o devtools/dump-gossipstore.o gossipd/gen_gossip_store.o devtools/dump-gossipstore.o: gossipd/gen_gossip_store.h + +devtools/create-gossipstore: $(DEVTOOLS_OBJS) $(DEVTOOLS_COMMON_OBJS) $(JSMN_OBJS) $(CCAN_OBJS) $(BITCOIN_OBJS) wire/fromwire.o wire/towire.o devtools/create-gossipstore.o gossipd/gen_gossip_store.o +devtools/create-gossipstore.o: gossipd/gen_gossip_store.h + devtools/onion.c: ccan/config.h devtools/onion: $(DEVTOOLS_OBJS) $(DEVTOOLS_COMMON_OBJS) $(JSMN_OBJS) $(CCAN_OBJS) $(BITCOIN_OBJS) wire/fromwire.o wire/towire.o devtools/onion.o common/sphinx.o diff --git a/devtools/create-gossipstore.c b/devtools/create-gossipstore.c new file mode 100644 index 000000000000..91d93262a2ed --- /dev/null +++ b/devtools/create-gossipstore.c @@ -0,0 +1,186 @@ +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + + +struct scidsat { + struct short_channel_id scid; + struct amount_sat sat; +} scidsat; + +/* read scid,satoshis csv file and create return an array of scidsat pointers */ +static struct scidsat *load_csv_file(FILE *scidf) +{ + int n, r; + char title[15]; + int i = 0; + struct scidsat *scidsats; + /* max characters is 8 (0xffffff) + 8 for tx + 5 (0xffffff) for outputs (0xffff) + 2 (x's) */ + char str[23]; + + if (fscanf(scidf, "%d\n", &n) != 1) + err(1, "reading number of entries from csv failed"); + + scidsats = tal_arr(NULL, struct scidsat, n); + r = fscanf(scidf, "%5s ,%8s\n", title, &title[6]); + if (r != 2 || strcmp(title, "scid") != 0 || strcmp(&title[6], "satoshis") != 0) + err(1, "reading 'scid ,satoshis' from csv failed"); + + while(fscanf(scidf, "%s ,%ld\n", str, &scidsats[i].sat.satoshis) == 2 ) { /* Raw: read from file */ + if (!short_channel_id_from_str(str, strlen(str), &scidsats[i].scid, 0)) + err(1, "failed to make scid struct"); + i++; + } + return scidsats; +} + +static u64 getScid(const u8 *msg, size_t *max) { + const u8 ** cursor = &msg; + return fromwire_u64(cursor, max); +} + +int main(int argc, char *argv[]) +{ + u8 version; + beint16_t be_inlen; + struct amount_sat sat; + bool verbose = false; + char *infile = NULL, *outfile = NULL, *csvfile = NULL, *csat = NULL; + int infd, outfd, scidi, channelsi, nodesi, updatesi, msgi = 0; + u64 scid; + short featurelen; + struct scidsat *scidsats; + unsigned max = -1U; + size_t plen; + + setup_locale(); + + opt_register_noarg("--verbose|-v", opt_set_bool, &verbose, + "Print progress to stderr"); + opt_register_arg("--output|-o", opt_set_charp, NULL, &outfile, + "Send output to this file instead of stdout"); + opt_register_arg("--input|-i", opt_set_charp, NULL, &infile, + "Read input from this file instead of stdin"); + opt_register_arg("--csv", opt_set_charp, NULL, &csvfile, + "Input for 'scid, satshis' csv"); + opt_register_arg("--sat", opt_set_charp, NULL, &csat, + "default satoshi value if --csv flag not present"); + opt_register_arg("--max", opt_set_uintval, opt_show_uintval, &max, + "maximum number of messages to read"); + opt_register_noarg("--help|-h", opt_usage_and_exit, + "Create gossip store, from be16 / input messages", + "Print this message."); + + opt_parse(&argc, argv, opt_log_stderr_exit); + + + if (csvfile && !csat) { + FILE *scidf; + scidf = fopen(csvfile, "r"); + if (!scidf) + err(1, "opening %s", csvfile); + scidsats = load_csv_file(scidf); + fclose(scidf); + } else if (csat && !csvfile) { + if (!parse_amount_sat(&sat, csat, strlen(csat))) { + errx(1, "Invalid satoshi amount %s", csat); + } + } + else { + err(1, "must contain either --sat xor --csvfile"); + } + + if (infile) { + infd = open(infile, O_RDONLY); + if (!infd) + err(1, "opening %s", infile); + } + + if (outfile) { + outfd = open(outfile, O_WRONLY|O_TRUNC|O_CREAT, 0666); + if (outfd < 0) + err(1, "opening %s", outfile); + } else + outfd = STDOUT_FILENO; + + version = GOSSIP_STORE_VERSION; + if (!write_all(outfd, &version, sizeof(version))) + err(1, "Writing version"); + + while (read_all(infd, &be_inlen, sizeof(be_inlen))) { + u32 msglen = be16_to_cpu(be_inlen); + u8 *inmsg = tal_arr(NULL, u8, msglen), *outmsg; + beint32_t be_outlen; + beint32_t becsum; + + if (!read_all(infd, inmsg, msglen)) + err(1, "Only read partial message"); + + switch (fromwire_peektype(inmsg)) { + case WIRE_CHANNEL_ANNOUNCEMENT: + if (csvfile) { + sat = scidsats[scidi].sat; + msgi = 258; + featurelen = *(short *)(&inmsg[msgi]); + msgi += 2 + (int)featurelen + 32; + plen = tal_count(inmsg); + scid = getScid(&inmsg[msgi], &plen); + if (scid != scidsats[scidi].scid.u64) + err(1, "scid of message does not match scid in csv"); + scidi++; + } + outmsg = towire_gossip_store_channel_announcement(inmsg, inmsg, sat); + channelsi += 1; + break; + case WIRE_CHANNEL_UPDATE: + outmsg = towire_gossip_store_channel_update(inmsg, inmsg); + updatesi += 1; + break; + case WIRE_NODE_ANNOUNCEMENT: + outmsg = towire_gossip_store_node_announcement(inmsg, inmsg); + nodesi += 1; + break; + default: + warnx("Unknown message %u (%s)", fromwire_peektype(inmsg), + wire_type_name(fromwire_peektype(inmsg))); + tal_free(inmsg); + continue; + } + if (verbose) + fprintf(stderr, "%s->%s\n", + wire_type_name(fromwire_peektype(inmsg)), + gossip_store_type_name(fromwire_peektype(outmsg))); + + becsum = cpu_to_be32(crc32c(0, outmsg, tal_count(outmsg))); + be_outlen = cpu_to_be32(tal_count(outmsg)); + if (!write_all(outfd, &be_outlen, sizeof(be_outlen)) + || !write_all(outfd, &becsum, sizeof(becsum)) + || !write_all(outfd, outmsg, tal_count(outmsg))) { + exit(1); + } + tal_free(inmsg); + if (--max == 0) + break; + } + fprintf(stderr, "channels %d, updates %d, nodes %d\n", channelsi, updatesi, nodesi); + if (csvfile) + tal_free(scidsats); + return 0; +} diff --git a/devtools/gossipwith.c b/devtools/gossipwith.c index e4f2a9808ff1..2c0b74490483 100644 --- a/devtools/gossipwith.c +++ b/devtools/gossipwith.c @@ -14,6 +14,7 @@ #define io_write_ simple_write #define io_read_ simple_read #define io_close simple_close +static bool stream_stdin = false; static struct io_plan *simple_write(struct io_conn *conn, const void *data, size_t len, @@ -130,6 +131,19 @@ static struct io_plan *handshake_success(struct io_conn *conn, tal_free(sync_crypto_read(NULL, &cs, conn->fd)); /* Did they ask us to send any messages? Do so now. */ + if (stream_stdin) { + beint16_t be_inlen; + + while (read_all(STDIN_FILENO, &be_inlen, sizeof(be_inlen))) { + u32 msglen = be16_to_cpu(be_inlen); + u8 *msg = tal_arr(NULL, u8, msglen); + + if (!read_all(STDIN_FILENO, msg, msglen)) + err(1, "Only read partial message"); + sync_crypto_write(&cs, conn->fd, take(msg)); + } + } + while (*args) { u8 *m = tal_hexdata(NULL, *args, strlen(*args)); if (!m) @@ -172,6 +186,8 @@ int main(int argc, char *argv[]) opt_register_arg("--max-messages", opt_set_ulongval, opt_show_ulongval, &max_messages, "Terminate after reading this many messages (> 0)"); + opt_register_noarg("--stdin", opt_set_bool, &stream_stdin, + "Stream gossip messages from stdin."); opt_register_noarg("--help|-h", opt_usage_and_exit, "id@addr[:port] [hex-msg-tosend...]\n" "Connect to a lightning peer and relay gossip messages from it", diff --git a/gossipd/gossip_store.c b/gossipd/gossip_store.c index b791a0828e7c..aec25a4cb25b 100644 --- a/gossipd/gossip_store.c +++ b/gossipd/gossip_store.c @@ -150,19 +150,59 @@ static bool gossip_store_append(int fd, struct routing_state *rstate, const u8 * write(fd, msg, msglen) == msglen); } +/* Local unannounced channels don't appear in broadcast map, but we need to + * remember them anyway, so we manually append to the store. + * + * Note these do *not* add to gs->count, since that's compared with + * the broadcast map count. +*/ +static bool add_local_unnannounced(int fd, + struct routing_state *rstate, + struct node *self) +{ + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&self->chans, &i); + c; + c = chan_map_next(&self->chans, &i)) { + struct node *peer = other_node(self, c); + const u8 *msg; + + /* Ignore already announced. */ + if (c->channel_announce) + continue; + + msg = towire_gossipd_local_add_channel(tmpctx, &c->scid, + &peer->id, c->sat); + if (!gossip_store_append(fd, rstate, msg)) + return false; + + for (size_t i = 0; i < 2; i++) { + msg = c->half[i].channel_update; + if (!msg) + continue; + if (!gossip_store_append(fd, rstate, msg)) + return false; + } + } + + return true; +} + /** * Rewrite the on-disk gossip store, compacting it along the way * * Creates a new file, writes all the updates from the `broadcast_state`, and * then atomically swaps the files. */ - -static void gossip_store_compact(struct gossip_store *gs) +bool gossip_store_compact(struct gossip_store *gs) { size_t count = 0; u64 index = 0; int fd; const u8 *msg; + struct node *self; assert(gs->broadcast); status_trace( @@ -188,11 +228,18 @@ static void gossip_store_compact(struct gossip_store *gs) status_broken("Failed writing to gossip store: %s", strerror(errno)); goto unlink_disable; - } count++; } + /* Local unannounced channels are not in the store! */ + self = get_node(gs->rstate, &gs->rstate->local_id); + if (self && !add_local_unnannounced(fd, gs->rstate, self)) { + status_broken("Failed writing unannounced to gossip store: %s", + strerror(errno)); + goto unlink_disable; + } + if (rename(GOSSIP_STORE_TEMP_FILENAME, GOSSIP_STORE_FILENAME) == -1) { status_broken( "Error swapping compacted gossip_store into place: %s", @@ -206,7 +253,7 @@ static void gossip_store_compact(struct gossip_store *gs) gs->count = count; close(gs->fd); gs->fd = fd; - return; + return true; unlink_disable: unlink(GOSSIP_STORE_TEMP_FILENAME); @@ -214,6 +261,7 @@ static void gossip_store_compact(struct gossip_store *gs) status_trace("Encountered an error while compacting, disabling " "future compactions."); gs->disable_compaction = true; + return false; } void gossip_store_add(struct gossip_store *gs, const u8 *gossip_msg) @@ -255,6 +303,7 @@ void gossip_store_load(struct routing_state *rstate, struct gossip_store *gs) size_t stats[] = {0, 0, 0, 0}; int fd = gs->fd; gs->fd = -1; + struct timeabs start = time_now(); if (lseek(fd, known_good, SEEK_SET) < 0) { status_unusual("gossip_store: lseek failure"); @@ -333,6 +382,15 @@ void gossip_store_load(struct routing_state *rstate, struct gossip_store *gs) status_failed(STATUS_FAIL_INTERNAL_ERROR, "Truncating store: %s", strerror(errno)); out: +#if DEVELOPER + status_info("total store load time: %"PRIu64" msec (%zu entries, %zu bytes)", + time_to_msec(time_between(time_now(), start)), + stats[0] + stats[1] + stats[2] + stats[3], + (size_t)known_good); +#else + status_trace("total store load time: %"PRIu64" msec", + time_to_msec(time_between(time_now(), start))); +#endif status_trace("gossip_store: Read %zu/%zu/%zu/%zu cannounce/cupdate/nannounce/cdelete from store in %"PRIu64" bytes", stats[0], stats[1], stats[2], stats[3], (u64)known_good); diff --git a/gossipd/gossip_store.h b/gossipd/gossip_store.h index 03406fcf65c1..a25004458254 100644 --- a/gossipd/gossip_store.h +++ b/gossipd/gossip_store.h @@ -39,4 +39,6 @@ void gossip_store_add(struct gossip_store *gs, const u8 *gossip_msg); void gossip_store_add_channel_delete(struct gossip_store *gs, const struct short_channel_id *scid); +/* Expose for dev-compact-gossip-store */ +bool gossip_store_compact(struct gossip_store *gs); #endif /* LIGHTNING_GOSSIPD_GOSSIP_STORE_H */ diff --git a/gossipd/gossip_wire.csv b/gossipd/gossip_wire.csv index 4d1b9e5d822b..8c6ffb4702a9 100644 --- a/gossipd/gossip_wire.csv +++ b/gossipd/gossip_wire.csv @@ -14,6 +14,8 @@ gossipctl_init,,alias,32*u8 gossipctl_init,,update_channel_interval,u32 gossipctl_init,,num_announcable,u16 gossipctl_init,,announcable,num_announcable*struct wireaddr +gossipctl_init,,dev_gossip_time,?u32 +gossipctl_init,,dev_unknown_channel_satoshis,?struct amount_sat # Pass JSON-RPC getnodes call through gossip_getnodes_request,3005 @@ -140,6 +142,13 @@ gossip_dev_memleak,3033 gossip_dev_memleak_reply,3133 gossip_dev_memleak_reply,,leak,bool +# master -> gossipd: please rewrite the gossip_store +gossip_dev_compact_store,3034 + +# gossipd -> master: ok +gossip_dev_compact_store_reply,3134 +gossip_dev_compact_store_reply,,success,bool + #include # master -> gossipd: get route_info for our incoming channels diff --git a/gossipd/gossipd.c b/gossipd/gossipd.c index 957aadaaec53..6213eda7fd26 100644 --- a/gossipd/gossipd.c +++ b/gossipd/gossipd.c @@ -175,8 +175,12 @@ struct peer { static void peer_disable_channels(struct daemon *daemon, struct node *node) { /* If this peer had a channel with us, mark it disabled. */ - for (size_t i = 0; i < tal_count(node->chans); i++) { - struct chan *c = node->chans[i]; + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&node->chans, &i); + c; + c = chan_map_next(&node->chans, &i)) { if (pubkey_eq(&other_node(node, c)->id, &daemon->id)) c->local_disabled = true; } @@ -1798,8 +1802,13 @@ static void gossip_refresh_network(struct daemon *daemon) if (n) { /* Iterate through all outgoing connection and check whether * it's time to re-announce */ - for (size_t i = 0; i < tal_count(n->chans); i++) { - struct half_chan *hc = half_chan_from(n, n->chans[i]); + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&n->chans, &i); + c; + c = chan_map_next(&n->chans, &i)) { + struct half_chan *hc = half_chan_from(n, c); if (!is_halfchan_defined(hc)) { /* Connection is not announced yet, so don't even @@ -1817,7 +1826,7 @@ static void gossip_refresh_network(struct daemon *daemon) continue; } - gossip_send_keepalive_update(daemon, n->chans[i], hc); + gossip_send_keepalive_update(daemon, c, hc); } } @@ -1830,14 +1839,18 @@ static void gossip_refresh_network(struct daemon *daemon) static void gossip_disable_local_channels(struct daemon *daemon) { struct node *local_node = get_node(daemon->rstate, &daemon->id); + struct chan_map_iter i; + struct chan *c; /* We don't have a local_node, so we don't have any channels yet * either */ if (!local_node) return; - for (size_t i = 0; i < tal_count(local_node->chans); i++) - local_node->chans[i]->local_disabled = true; + for (c = chan_map_first(&local_node->chans, &i); + c; + c = chan_map_next(&local_node->chans, &i)) + c->local_disabled = true; } /*~ Parse init message from lightningd: starts the daemon properly. */ @@ -1846,6 +1859,8 @@ static struct io_plan *gossip_init(struct io_conn *conn, const u8 *msg) { u32 update_channel_interval; + u32 *dev_gossip_time; + struct amount_sat *dev_unknown_channel_satoshis; if (!fromwire_gossipctl_init(daemon, msg, /* 60,000 ms @@ -1858,7 +1873,9 @@ static struct io_plan *gossip_init(struct io_conn *conn, /* 1 week in seconds * (unless --dev-channel-update-interval) */ &update_channel_interval, - &daemon->announcable)) { + &daemon->announcable, + &dev_gossip_time, + &dev_unknown_channel_satoshis)) { master_badmsg(WIRE_GOSSIPCTL_INIT, msg); } @@ -1866,7 +1883,9 @@ static struct io_plan *gossip_init(struct io_conn *conn, daemon->rstate = new_routing_state(daemon, chainparams_by_chainhash(&daemon->chain_hash), &daemon->id, - update_channel_interval * 2); + update_channel_interval * 2, + dev_gossip_time, + dev_unknown_channel_satoshis); /* Load stored gossip messages */ gossip_store_load(daemon->rstate, daemon->rstate->store); @@ -2013,11 +2032,16 @@ static struct io_plan *getchannels_req(struct io_conn *conn, } else if (source) { struct node *s = get_node(daemon->rstate, source); if (s) { - for (size_t i = 0; i < tal_count(s->chans); i++) + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&s->chans, &i); + c; + c = chan_map_next(&s->chans, &i)) { append_half_channel(&entries, - s->chans[i], - !half_chan_to(s, - s->chans[i])); + c, + !half_chan_to(s, c)); + } } } else { u64 idx; @@ -2152,10 +2176,15 @@ static struct io_plan *ping_req(struct io_conn *conn, struct daemon *daemon, static bool node_has_public_channels(const struct node *peer, const struct chan *exclude) { - for (size_t i = 0; i < tal_count(peer->chans); i++) { - if (peer->chans[i] == exclude) + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&peer->chans, &i); + c; + c = chan_map_next(&peer->chans, &i)) { + if (c == exclude) continue; - if (is_chan_public(peer->chans[i])) + if (is_chan_public(c)) return true; } return false; @@ -2200,8 +2229,12 @@ static struct io_plan *get_incoming_channels(struct io_conn *conn, node = get_node(daemon->rstate, &daemon->rstate->local_id); if (node) { - for (size_t i = 0; i < tal_count(node->chans); i++) { - const struct chan *c = node->chans[i]; + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&node->chans, &i); + c; + c = chan_map_next(&node->chans, &i)) { const struct half_chan *hc; struct route_info ri; @@ -2457,6 +2490,17 @@ static struct io_plan *dev_gossip_memleak(struct io_conn *conn, found_leak))); return daemon_conn_read_next(conn, daemon->master); } + +static struct io_plan *dev_compact_store(struct io_conn *conn, + struct daemon *daemon, + const u8 *msg) +{ + bool done = gossip_store_compact(daemon->rstate->store); + daemon_conn_send(daemon->master, + take(towire_gossip_dev_compact_store_reply(NULL, + done))); + return daemon_conn_read_next(conn, daemon->master); +} #endif /* DEVELOPER */ /*~ lightningd: so, tell me about this channel, so we can forward to it. */ @@ -2716,6 +2760,8 @@ static struct io_plan *recv_req(struct io_conn *conn, return dev_gossip_suppress(conn, daemon, msg); case WIRE_GOSSIP_DEV_MEMLEAK: return dev_gossip_memleak(conn, daemon, msg); + case WIRE_GOSSIP_DEV_COMPACT_STORE: + return dev_compact_store(conn, daemon, msg); #else case WIRE_GOSSIP_QUERY_SCIDS: case WIRE_GOSSIP_SEND_TIMESTAMP_FILTER: @@ -2723,6 +2769,7 @@ static struct io_plan *recv_req(struct io_conn *conn, case WIRE_GOSSIP_DEV_SET_MAX_SCIDS_ENCODE_SIZE: case WIRE_GOSSIP_DEV_SUPPRESS: case WIRE_GOSSIP_DEV_MEMLEAK: + case WIRE_GOSSIP_DEV_COMPACT_STORE: break; #endif /* !DEVELOPER */ @@ -2737,6 +2784,7 @@ static struct io_plan *recv_req(struct io_conn *conn, case WIRE_GOSSIP_GET_INCOMING_CHANNELS_REPLY: case WIRE_GOSSIP_GET_TXOUT: case WIRE_GOSSIP_DEV_MEMLEAK_REPLY: + case WIRE_GOSSIP_DEV_COMPACT_STORE_REPLY: break; } diff --git a/gossipd/routing.c b/gossipd/routing.c index 1718e680c60f..0495b78d4b82 100644 --- a/gossipd/routing.c +++ b/gossipd/routing.c @@ -82,7 +82,9 @@ static struct node_map *empty_node_map(const tal_t *ctx) struct routing_state *new_routing_state(const tal_t *ctx, const struct chainparams *chainparams, const struct pubkey *local_id, - u32 prune_timeout) + u32 prune_timeout, + const u32 *dev_gossip_time, + const struct amount_sat *dev_unknown_channel_satoshis) { struct routing_state *rstate = tal(ctx, struct routing_state); rstate->nodes = empty_node_map(rstate); @@ -99,6 +101,16 @@ struct routing_state *new_routing_state(const tal_t *ctx, rstate->pending_node_map = tal(ctx, struct pending_node_map); pending_node_map_init(rstate->pending_node_map); +#if DEVELOPER + if (dev_gossip_time) { + rstate->gossip_time = tal(rstate, struct timeabs); + rstate->gossip_time->ts.tv_sec = *dev_gossip_time; + rstate->gossip_time->ts.tv_nsec = 0; + } else + rstate->gossip_time = NULL; + rstate->dev_unknown_channel_satoshis = dev_unknown_channel_satoshis; +#endif + return rstate; } @@ -120,11 +132,14 @@ bool node_map_node_eq(const struct node *n, const struct pubkey *key) static void destroy_node(struct node *node, struct routing_state *rstate) { + struct chan_map_iter i; + struct chan *c; node_map_del(rstate->nodes, node); - /* These remove themselves from the array. */ - while (tal_count(node->chans)) - tal_free(node->chans[0]); + /* These remove themselves from the map. */ + while ((c = chan_map_first(&node->chans, &i)) != NULL) + tal_free(c); + chan_map_clear(&node->chans); } struct node *get_node(struct routing_state *rstate, const struct pubkey *id) @@ -141,7 +156,7 @@ static struct node *new_node(struct routing_state *rstate, n = tal(rstate, struct node); n->id = *id; - n->chans = tal_arr(n, struct chan *, 0); + chan_map_init(&n->chans); n->globalfeatures = NULL; n->node_announcement = NULL; n->node_announcement_index = 0; @@ -156,9 +171,15 @@ static struct node *new_node(struct routing_state *rstate, /* We've received a channel_announce for a channel attached to this node */ static bool node_has_public_channels(struct node *node) { - for (size_t i = 0; i < tal_count(node->chans); i++) - if (is_chan_public(node->chans[i])) + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&node->chans, &i); + c; + c = chan_map_next(&node->chans, &i)) { + if (is_chan_public(c)) return true; + } return false; } @@ -166,39 +187,33 @@ static bool node_has_public_channels(struct node *node) * we only send once we have a channel_update. */ static bool node_has_broadcastable_channels(struct node *node) { - for (size_t i = 0; i < tal_count(node->chans); i++) { - if (!is_chan_public(node->chans[i])) - continue; - if (is_halfchan_defined(&node->chans[i]->half[0]) - || is_halfchan_defined(&node->chans[i]->half[1])) - return true; - } - return false; -} - -static bool remove_channel_from_array(struct chan ***chans, const struct chan *c) -{ - size_t i, n; + struct chan_map_iter i; + struct chan *c; - n = tal_count(*chans); - for (i = 0; i < n; i++) { - if ((*chans)[i] != c) + for (c = chan_map_first(&node->chans, &i); + c; + c = chan_map_next(&node->chans, &i)) { + if (!is_chan_public(c)) continue; - n--; - memmove(*chans + i, *chans + i + 1, sizeof(**chans) * (n - i)); - tal_resize(chans, n); - return true; + if (is_halfchan_defined(&c->half[0]) + || is_halfchan_defined(&c->half[1])) + return true; } return false; } static bool node_announce_predates_channels(const struct node *node) { - for (size_t i = 0; i < tal_count(node->chans); i++) { - if (!is_chan_announced(node->chans[i])) + struct chan_map_iter i; + struct chan *c; + + for (c = chan_map_first(&node->chans, &i); + c; + c = chan_map_next(&node->chans, &i)) { + if (!is_chan_announced(c)) continue; - if (node->chans[i]->channel_announcement_index + if (c->channel_announcement_index < node->node_announcement_index) return false; } @@ -216,11 +231,11 @@ static u64 persistent_broadcast(struct routing_state *rstate, const u8 *msg, u32 static void remove_chan_from_node(struct routing_state *rstate, struct node *node, const struct chan *chan) { - if (!remove_channel_from_array(&node->chans, chan)) + if (!chan_map_del(&node->chans, chan)) abort(); /* Last channel? Simply delete node (and associated announce) */ - if (tal_count(node->chans) == 0) { + if (node->chans.raw.elems == 0) { tal_free(node); return; } @@ -267,7 +282,7 @@ static void init_half_chan(struct routing_state *rstate, c->message_flags = 0; /* We haven't seen channel_update: make it halfway to prune time, * which should be older than any update we'd see. */ - c->last_timestamp = time_now().ts.tv_sec - rstate->prune_timeout/2; + c->last_timestamp = gossip_time_now(rstate).ts.tv_sec - rstate->prune_timeout/2; } static void bad_gossip_order(const u8 *msg, const char *source, @@ -308,8 +323,8 @@ struct chan *new_chan(struct routing_state *rstate, chan->sat = satoshis; chan->local_disabled = false; - tal_arr_expand(&n2->chans, chan); - tal_arr_expand(&n1->chans, chan); + chan_map_add(&n2->chans, chan); + chan_map_add(&n1->chans, chan); /* Populate with (inactive) connections */ init_half_chan(rstate, chan, n1idx); @@ -520,15 +535,20 @@ find_route(const tal_t *ctx, struct routing_state *rstate, for (n = node_map_first(rstate->nodes, &it); n; n = node_map_next(rstate->nodes, &it)) { - size_t num_edges = tal_count(n->chans); - for (i = 0; i < num_edges; i++) { - struct chan *chan = n->chans[i]; + struct chan_map_iter i; + struct chan *chan; + + for (chan = chan_map_first(&n->chans, &i); + chan; + chan = chan_map_next(&n->chans, &i)) { int idx = half_chan_to(n, chan); - SUPERVERBOSE("Node %s edge %i/%zu", + SUPERVERBOSE("Node %s edge %s", type_to_string(tmpctx, struct pubkey, &n->id), - i, num_edges); + type_to_string(tmpctx, + struct short_channel_id, + &c->scid)); if (!hc_is_routable(chan, idx)) { SUPERVERBOSE("...unroutable (local_disabled = %i, is_halfchan_enabled = %i, unroutable_until = %i", @@ -994,6 +1014,16 @@ void handle_pending_cannouncement(struct routing_state *rstate, if (!pending) return; +#if DEVELOPER + if (rstate->dev_unknown_channel_satoshis) { + outscript = scriptpubkey_p2wsh(pending, + bitcoin_redeem_2of2(pending, + &pending->bitcoin_key_1, + &pending->bitcoin_key_2)); + sat = *rstate->dev_unknown_channel_satoshis; + } +#endif + /* BOLT #7: * * The receiving node: @@ -1162,9 +1192,13 @@ bool routing_add_channel_update(struct routing_state *rstate, = tal_dup_arr(chan, u8, update, tal_count(update), 0); /* For private channels, we get updates without an announce: don't - * broadcast them! */ - if (!chan->channel_announce) + * broadcast them! But save local ones to store anyway. */ + if (!chan->channel_announce) { + if (is_local_channel(rstate, chan)) + gossip_store_add(rstate->store, + chan->half[direction].channel_update); return true; + } /* BOLT #7: * - MUST consider the `timestamp` of the `channel_announcement` to be @@ -1265,7 +1299,7 @@ u8 *handle_channel_update(struct routing_state *rstate, const u8 *update TAKES, * - if the `timestamp` is unreasonably far in the future: * - MAY discard the `channel_update`. */ - if (timestamp > time_now().ts.tv_sec + rstate->prune_timeout) { + if (timestamp > gossip_time_now(rstate).ts.tv_sec + rstate->prune_timeout) { status_debug("Received channel_update for %s with far time %u", type_to_string(tmpctx, struct short_channel_id, &short_channel_id), @@ -1274,7 +1308,7 @@ u8 *handle_channel_update(struct routing_state *rstate, const u8 *update TAKES, } /* Note: we can consider old timestamps a case of "instant prune" too */ - if (timestamp < time_now().ts.tv_sec - rstate->prune_timeout) { + if (timestamp < gossip_time_now(rstate).ts.tv_sec - rstate->prune_timeout) { status_debug("Received channel_update for %s with old time %u", type_to_string(tmpctx, struct short_channel_id, &short_channel_id), @@ -1669,13 +1703,18 @@ void routing_failure(struct routing_state *rstate, type_to_string(tmpctx, struct pubkey, erring_node_pubkey)); } else { + struct chan_map_iter i; + struct chan *c; + status_trace("Deleting node %s", type_to_string(tmpctx, struct pubkey, &node->id)); - for (size_t i = 0; i < tal_count(node->chans); ++i) { + for (c = chan_map_first(&node->chans, &i); + c; + c = chan_map_next(&node->chans, &i)) { /* Set it up to be pruned. */ - tal_steal(tmpctx, node->chans[i]); + tal_steal(tmpctx, c); } } } else { @@ -1708,7 +1747,7 @@ void routing_failure(struct routing_state *rstate, void route_prune(struct routing_state *rstate) { - u64 now = time_now().ts.tv_sec; + u64 now = gossip_time_now(rstate).ts.tv_sec; /* Anything below this highwater mark ought to be pruned */ const s64 highwater = now - rstate->prune_timeout; const tal_t *pruned = tal(NULL, char); @@ -1745,9 +1784,18 @@ void route_prune(struct routing_state *rstate) void memleak_remove_routing_tables(struct htable *memtable, const struct routing_state *rstate) { + struct node *n; + struct node_map_iter nit; + memleak_remove_htable(memtable, &rstate->nodes->raw); memleak_remove_htable(memtable, &rstate->pending_node_map->raw); memleak_remove_uintmap(memtable, &rstate->broadcasts->broadcasts); + + for (n = node_map_first(rstate->nodes, &nit); + n; + n = node_map_next(rstate->nodes, &nit)) { + memleak_remove_htable(memtable, &n->chans.raw); + } } #endif /* DEVELOPER */ @@ -1777,3 +1825,12 @@ bool handle_local_add_channel(struct routing_state *rstate, const u8 *msg) new_chan(rstate, &scid, &rstate->local_id, &remote_node_id, sat); return true; } + +struct timeabs gossip_time_now(const struct routing_state *rstate) +{ +#if DEVELOPER + if (rstate->gossip_time) + return *rstate->gossip_time; +#endif + return time_now(); +} diff --git a/gossipd/routing.h b/gossipd/routing.h index eb25756fd9ce..fcc35b6a6c45 100644 --- a/gossipd/routing.h +++ b/gossipd/routing.h @@ -85,6 +85,26 @@ static inline bool is_halfchan_enabled(const struct half_chan *hc) return is_halfchan_defined(hc) && !(hc->channel_flags & ROUTING_FLAGS_DISABLED); } +/* Container for per-node channel pointers. Better cache performance +* than uintmap, and we don't need ordering. */ +static inline const struct short_channel_id *chan_map_scid(const struct chan *c) +{ + return &c->scid; +} + +static inline size_t hash_scid(const struct short_channel_id *scid) +{ + /* scids cost money to generate, so simple hash works here */ + return (scid->u64 >> 32) ^ (scid->u64 >> 16) ^ scid->u64; +} + +static inline bool chan_eq_scid(const struct chan *c, + const struct short_channel_id *scid) +{ + return short_channel_id_eq(scid, &c->scid); +} +HTABLE_DEFINE_TYPE(struct chan, chan_map_scid, hash_scid, chan_eq_scid, chan_map); + struct node { struct pubkey id; @@ -95,7 +115,7 @@ struct node { struct wireaddr *addresses; /* Channels connecting us to other nodes */ - struct chan **chans; + struct chan_map chans; /* Temporary data for routefinding. */ struct { @@ -194,6 +214,15 @@ struct routing_state { /* Cache for txout queries that failed. Allows us to skip failed * checks if we get another announcement for the same scid. */ UINTMAP(bool) txout_failures; + +#if DEVELOPER + /* Override local time for gossip messages */ + struct timeabs *gossip_time; + + /* Instead of ignoring unknown channels, pretend they're valid + * with this many satoshis (if non-NULL) */ + const struct amount_sat *dev_unknown_channel_satoshis; +#endif }; static inline struct chan * @@ -214,7 +243,9 @@ struct route_hop { struct routing_state *new_routing_state(const tal_t *ctx, const struct chainparams *chainparams, const struct pubkey *local_id, - u32 prune_timeout); + u32 prune_timeout, + const u32 *dev_gossip_time, + const struct amount_sat *dev_unknown_channel_satoshis); /** * Add a new bidirectional channel from id1 to id2 with the given @@ -325,4 +356,12 @@ bool handle_local_add_channel(struct routing_state *rstate, const u8 *msg); void memleak_remove_routing_tables(struct htable *memtable, const struct routing_state *rstate); #endif + +/** + * Get the local time. + * + * This gets overridden in dev mode so we can use canned (stale) gossip. + */ +struct timeabs gossip_time_now(const struct routing_state *rstate); + #endif /* LIGHTNING_GOSSIPD_ROUTING_H */ diff --git a/gossipd/test/run-bench-find_route.c b/gossipd/test/run-bench-find_route.c index ad702243d9a0..cfdab2285780 100644 --- a/gossipd/test/run-bench-find_route.c +++ b/gossipd/test/run-bench-find_route.c @@ -95,6 +95,9 @@ u8 *towire_errorfmt(const tal_t *ctx UNNEEDED, const struct channel_id *channel UNNEEDED, const char *fmt UNNEEDED, ...) { fprintf(stderr, "towire_errorfmt called!\n"); abort(); } +/* Generated stub for towire_gossipd_local_add_channel */ +u8 *towire_gossipd_local_add_channel(const tal_t *ctx UNNEEDED, const struct short_channel_id *short_channel_id UNNEEDED, const struct pubkey *remote_node_id UNNEEDED, struct amount_sat satoshis UNNEEDED) +{ fprintf(stderr, "towire_gossipd_local_add_channel called!\n"); abort(); } /* Generated stub for towire_gossip_store_channel_announcement */ u8 *towire_gossip_store_channel_announcement(const tal_t *ctx UNNEEDED, const u8 *announcement UNNEEDED, struct amount_sat satoshis UNNEEDED) { fprintf(stderr, "towire_gossip_store_channel_announcement called!\n"); abort(); } @@ -225,7 +228,7 @@ int main(int argc, char *argv[]) setup_tmpctx(); me = nodeid(0); - rstate = new_routing_state(tmpctx, NULL, &me, 0); + rstate = new_routing_state(tmpctx, NULL, &me, 0, NULL, NULL); opt_register_noarg("--perfme", opt_set_bool, &perfme, "Run perfme-start and perfme-stop around benchmark"); diff --git a/gossipd/test/run-find_route-specific.c b/gossipd/test/run-find_route-specific.c index f3c73bf14a53..d39bf64f7307 100644 --- a/gossipd/test/run-find_route-specific.c +++ b/gossipd/test/run-find_route-specific.c @@ -84,6 +84,9 @@ u8 *towire_errorfmt(const tal_t *ctx UNNEEDED, const struct channel_id *channel UNNEEDED, const char *fmt UNNEEDED, ...) { fprintf(stderr, "towire_errorfmt called!\n"); abort(); } +/* Generated stub for towire_gossipd_local_add_channel */ +u8 *towire_gossipd_local_add_channel(const tal_t *ctx UNNEEDED, const struct short_channel_id *short_channel_id UNNEEDED, const struct pubkey *remote_node_id UNNEEDED, struct amount_sat satoshis UNNEEDED) +{ fprintf(stderr, "towire_gossipd_local_add_channel called!\n"); abort(); } /* Generated stub for towire_gossip_store_channel_announcement */ u8 *towire_gossip_store_channel_announcement(const tal_t *ctx UNNEEDED, const u8 *announcement UNNEEDED, struct amount_sat satoshis UNNEEDED) { fprintf(stderr, "towire_gossip_store_channel_announcement called!\n"); abort(); } @@ -184,7 +187,7 @@ int main(void) strlen("02cca6c5c966fcf61d121e3a70e03a1cd9eeeea024b26ea666ce974d43b242e636"), &d); - rstate = new_routing_state(tmpctx, NULL, &a, 0); + rstate = new_routing_state(tmpctx, NULL, &a, 0, NULL, NULL); /* [{'active': True, 'short_id': '6990:2:1/1', 'fee_per_kw': 10, 'delay': 5, 'message_flags': 0, 'channel_flags': 1, 'destination': '0230ad0e74ea03976b28fda587bb75bdd357a1938af4424156a18265167f5e40ae', 'source': '02ea622d5c8d6143f15ed3ce1d501dd0d3d09d3b1c83a44d0034949f8a9ab60f06', 'last_update': 1504064344}, */ diff --git a/gossipd/test/run-find_route.c b/gossipd/test/run-find_route.c index 750538821f52..6d644c4828da 100644 --- a/gossipd/test/run-find_route.c +++ b/gossipd/test/run-find_route.c @@ -82,6 +82,9 @@ u8 *towire_errorfmt(const tal_t *ctx UNNEEDED, const struct channel_id *channel UNNEEDED, const char *fmt UNNEEDED, ...) { fprintf(stderr, "towire_errorfmt called!\n"); abort(); } +/* Generated stub for towire_gossipd_local_add_channel */ +u8 *towire_gossipd_local_add_channel(const tal_t *ctx UNNEEDED, const struct short_channel_id *short_channel_id UNNEEDED, const struct pubkey *remote_node_id UNNEEDED, struct amount_sat satoshis UNNEEDED) +{ fprintf(stderr, "towire_gossipd_local_add_channel called!\n"); abort(); } /* Generated stub for towire_gossip_store_channel_announcement */ u8 *towire_gossip_store_channel_announcement(const tal_t *ctx UNNEEDED, const u8 *announcement UNNEEDED, struct amount_sat satoshis UNNEEDED) { fprintf(stderr, "towire_gossip_store_channel_announcement called!\n"); abort(); } @@ -149,14 +152,16 @@ static struct chan *find_channel(struct routing_state *rstate UNUSED, const struct node *to, int *idx) { - int i, n; + struct chan_map_iter i; + struct chan *c; *idx = pubkey_idx(&from->id, &to->id); - n = tal_count(to->chans); - for (i = 0; i < n; i++) { - if (to->chans[i]->nodes[*idx] == from) - return to->chans[i]; + for (c = chan_map_first(&to->chans, &i); + c; + c = chan_map_next(&to->chans, &i)) { + if (c->nodes[*idx] == from) + return c; } return NULL; } @@ -211,7 +216,7 @@ int main(void) memset(&tmp, 'a', sizeof(tmp)); pubkey_from_privkey(&tmp, &a); - rstate = new_routing_state(tmpctx, NULL, &a, 0); + rstate = new_routing_state(tmpctx, NULL, &a, 0, NULL, NULL); new_node(rstate, &a); diff --git a/lightningd/gossip_control.c b/lightningd/gossip_control.c index 6b8ffdae1aca..e316d6a344a3 100644 --- a/lightningd/gossip_control.c +++ b/lightningd/gossip_control.c @@ -121,6 +121,7 @@ static unsigned gossip_msg(struct subd *gossip, const u8 *msg, const int *fds) case WIRE_GOSSIP_DEV_SUPPRESS: case WIRE_GOSSIP_LOCAL_CHANNEL_CLOSE: case WIRE_GOSSIP_DEV_MEMLEAK: + case WIRE_GOSSIP_DEV_COMPACT_STORE: /* This is a reply, so never gets through to here. */ case WIRE_GOSSIP_GETNODES_REPLY: case WIRE_GOSSIP_GETROUTE_REPLY: @@ -130,6 +131,7 @@ static unsigned gossip_msg(struct subd *gossip, const u8 *msg, const int *fds) case WIRE_GOSSIP_GET_CHANNEL_PEER_REPLY: case WIRE_GOSSIP_GET_INCOMING_CHANNELS_REPLY: case WIRE_GOSSIP_DEV_MEMLEAK_REPLY: + case WIRE_GOSSIP_DEV_COMPACT_STORE_REPLY: break; case WIRE_GOSSIP_PING_REPLY: @@ -164,7 +166,15 @@ void gossip_init(struct lightningd *ld, int connectd_fd) get_offered_globalfeatures(tmpctx), ld->rgb, ld->alias, ld->config.channel_update_interval, - ld->announcable); + ld->announcable, +#if DEVELOPER + ld->dev_gossip_time ? &ld->dev_gossip_time: NULL, + ld->dev_unknown_channel_satoshis +#else + NULL, + NULL +#endif + ); subd_send_msg(ld->gossip, msg); } @@ -672,4 +682,46 @@ static const struct json_command dev_suppress_gossip = { "Stop this node from sending any more gossip." }; AUTODATA(json_command, &dev_suppress_gossip); + +static void dev_compact_gossip_store_reply(struct subd *gossip UNUSED, + const u8 *reply, + const int *fds UNUSED, + struct command *cmd) +{ + bool success; + + if (!fromwire_gossip_dev_compact_store_reply(reply, &success)) { + was_pending(command_fail(cmd, LIGHTNINGD, + "Gossip gave bad dev_gossip_compact_store_reply")); + return; + } + + if (!success) + was_pending(command_fail(cmd, LIGHTNINGD, + "gossip_compact_store failed")); + else + was_pending(command_success(cmd, null_response(cmd))); +} + +static struct command_result *json_dev_compact_gossip_store(struct command *cmd, + const char *buffer, + const jsmntok_t *obj UNNEEDED, + const jsmntok_t *params) +{ + u8 *msg; + if (!param(cmd, buffer, params, NULL)) + return command_param_failed(); + + msg = towire_gossip_dev_compact_store(NULL); + subd_req(cmd->ld->gossip, cmd->ld->gossip, + take(msg), -1, 0, dev_compact_gossip_store_reply, cmd); + return command_still_pending(cmd); +} + +static const struct json_command dev_compact_gossip_store = { + "dev-compact-gossip-store", + json_dev_compact_gossip_store, + "Ask gossipd to rewrite the gossip store." +}; +AUTODATA(json_command, &dev_compact_gossip_store); #endif /* DEVELOPER */ diff --git a/lightningd/json_stream.c b/lightningd/json_stream.c index a26f77bae7cb..80695244b7af 100644 --- a/lightningd/json_stream.c +++ b/lightningd/json_stream.c @@ -116,8 +116,6 @@ static void js_written_some(struct json_stream *js) void json_stream_append_part(struct json_stream *js, const char *str, size_t len) { mkroom(js, len); - if (js->log) - log_io(js->log, LOG_IO_OUT, "", str, len); memcpy(membuf_add(&js->outbuf, len), str, len); js_written_some(js); } @@ -148,9 +146,6 @@ static void json_stream_append_vfmt(struct json_stream *js, mkroom(js, fmtlen + 1); vsprintf(membuf_space(&js->outbuf), fmt, ap2); } - if (js->log) - log_io(js->log, LOG_IO_OUT, "", - membuf_space(&js->outbuf), fmtlen); membuf_added(&js->outbuf, fmtlen); js_written_some(js); va_end(ap2); @@ -296,6 +291,9 @@ static struct io_plan *json_stream_output_write(struct io_conn *conn, } js->reader = conn; + if (js->log) + log_io(js->log, LOG_IO_OUT, "", + membuf_elems(&js->outbuf), js->len_read); return io_write(conn, membuf_elems(&js->outbuf), js->len_read, json_stream_output_write, js); diff --git a/lightningd/lightningd.c b/lightningd/lightningd.c index b26441d996b9..76895922027a 100644 --- a/lightningd/lightningd.c +++ b/lightningd/lightningd.c @@ -116,6 +116,8 @@ static struct lightningd *new_lightningd(const tal_t *ctx) ld->dev_disconnect_fd = -1; ld->dev_subdaemon_fail = false; ld->dev_allow_localhost = false; + ld->dev_gossip_time = 0; + ld->dev_unknown_channel_satoshis = NULL; #endif /*~ These are CCAN lists: an embedded double-linked list. It's not diff --git a/lightningd/lightningd.h b/lightningd/lightningd.h index 680e45dcd80d..11d047154c2d 100644 --- a/lightningd/lightningd.h +++ b/lightningd/lightningd.h @@ -196,6 +196,12 @@ struct lightningd { /* Allow and accept localhost node_announcement addresses */ bool dev_allow_localhost; + /* Timestamp to use for gossipd, iff non-zero */ + u32 dev_gossip_time; + + /* What to override unknown channels with, iff non-NULL */ + struct amount_sat *dev_unknown_channel_satoshis; + /* Things we've marked as not leaking. */ const void **notleaks; #endif /* DEVELOPER */ diff --git a/lightningd/log.c b/lightningd/log.c index ef02ced2c77d..e0fbec20ceac 100644 --- a/lightningd/log.c +++ b/lightningd/log.c @@ -49,7 +49,9 @@ struct log_book { enum log_level level, bool continued, const struct timeabs *time, - const char *str, const u8 *io, void *arg); + const char *str, + const u8 *io, size_t io_len, + void *arg); void *print_arg; enum log_level print_level; struct timeabs init_time; @@ -68,6 +70,7 @@ static void log_to_file(const char *prefix, const struct timeabs *time, const char *str, const u8 *io, + size_t io_len, FILE *logf) { char iso8601_msec_fmt[sizeof("YYYY-mm-ddTHH:MM:SS.%03dZ")]; @@ -77,7 +80,7 @@ static void log_to_file(const char *prefix, if (level == LOG_IO_IN || level == LOG_IO_OUT) { const char *dir = level == LOG_IO_IN ? "[IN]" : "[OUT]"; - char *hex = tal_hex(NULL, io); + char *hex = tal_hexstr(NULL, io, io_len); fprintf(logf, "%s %s%s%s %s\n", iso8601_s, prefix, str, dir, hex); tal_free(hex); @@ -94,9 +97,10 @@ static void log_to_stdout(const char *prefix, bool continued, const struct timeabs *time, const char *str, - const u8 *io, void *unused UNUSED) + const u8 *io, size_t io_len, + void *unused UNUSED) { - log_to_file(prefix, level, continued, time, str, io, stdout); + log_to_file(prefix, level, continued, time, str, io, io_len, stdout); } static size_t mem_used(const struct log_entry *e) @@ -191,7 +195,9 @@ void set_log_outfn_(struct log_book *lr, enum log_level level, bool continued, const struct timeabs *time, - const char *str, const u8 *io, void *arg), + const char *str, + const u8 *io, size_t io_len, + void *arg), void *arg) { lr->print = print; @@ -250,7 +256,7 @@ static void maybe_print(const struct log *log, const struct log_entry *l, if (l->level >= log->lr->print_level) log->lr->print(log->prefix, l->level, offset != 0, &l->time, l->log + offset, - l->io, log->lr->print_arg); + l->io, tal_bytelen(l->io), log->lr->print_arg); } void logv(struct log *log, enum log_level level, const char *fmt, va_list ap) @@ -282,10 +288,21 @@ void log_io(struct log *log, enum log_level dir, assert(dir == LOG_IO_IN || dir == LOG_IO_OUT); + /* Print first, in case we need to truncate. */ + if (l->level >= log->lr->print_level) + log->lr->print(log->prefix, l->level, false, + &l->time, str, + data, len, log->lr->print_arg); + l->log = tal_strdup(l, str); + + /* Don't immediately fill buffer with giant IOs */ + if (len > log->lr->max_mem / 64) { + l->skipped++; + len = log->lr->max_mem / 64; + } l->io = tal_dup_arr(l, u8, data, len, 0); - maybe_print(log, l, 0); add_entry(log, l); errno = save_errno; } diff --git a/lightningd/log.h b/lightningd/log.h index fb38a316cfc9..0e74bc4aaffc 100644 --- a/lightningd/log.h +++ b/lightningd/log.h @@ -50,7 +50,7 @@ struct log_book *get_log_book(const struct log *log); bool, \ const struct timeabs *, \ const char *, \ - const u8 *), (arg)) + const u8 *, size_t), (arg)) /* If level == LOG_IO_IN/LOG_IO_OUT, then io contains data */ void set_log_outfn_(struct log_book *lr, @@ -59,7 +59,7 @@ void set_log_outfn_(struct log_book *lr, bool continued, const struct timeabs *time, const char *str, - const u8 *io, + const u8 *io, size_t io_len, void *arg), void *arg); diff --git a/lightningd/options.c b/lightningd/options.c index 146711b1ab09..8e6209e715d6 100644 --- a/lightningd/options.c +++ b/lightningd/options.c @@ -443,6 +443,15 @@ static char *opt_subprocess_debug(const char *optarg, struct lightningd *ld) return NULL; } +static char *opt_set_dev_unknown_channel_satoshis(const char *optarg, + struct lightningd *ld) +{ + tal_free(ld->dev_unknown_channel_satoshis); + ld->dev_unknown_channel_satoshis = tal(ld, struct amount_sat); + return opt_set_u64(optarg, + &ld->dev_unknown_channel_satoshis->satoshis); /* Raw: dev code */ +} + static void dev_register_opts(struct lightningd *ld) { opt_register_noarg("--dev-no-reconnect", opt_set_invbool, @@ -475,6 +484,13 @@ static void dev_register_opts(struct lightningd *ld) "--dev-channel-update-interval=", opt_set_u32, opt_show_u32, &ld->config.channel_update_interval, "Time in seconds between channel updates for our own channels."); + + opt_register_arg("--dev-gossip-time", opt_set_u32, opt_show_u32, + &ld->dev_gossip_time, + "UNIX time to override gossipd to use."); + opt_register_arg("--dev-unknown-channel-satoshis", + opt_set_dev_unknown_channel_satoshis, NULL, ld, + "Amount to pretend is in channels which we can't find funding tx for."); } #endif diff --git a/lightningd/peer_control.c b/lightningd/peer_control.c index 909be0ca1e3c..20e815976823 100644 --- a/lightningd/peer_control.c +++ b/lightningd/peer_control.c @@ -72,11 +72,11 @@ static void copy_to_parent_log(const char *prefix, bool continued, const struct timeabs *time UNUSED, const char *str, - const u8 *io, + const u8 *io, size_t io_len, struct log *parent_log) { if (level == LOG_IO_IN || level == LOG_IO_OUT) - log_io(parent_log, level, prefix, io, tal_count(io)); + log_io(parent_log, level, prefix, io, io_len); else if (continued) log_add(parent_log, "%s ... %s", prefix, str); else diff --git a/lightningd/test/run-invoice-select-inchan.c b/lightningd/test/run-invoice-select-inchan.c index 36564de834cf..42e711ced0cf 100644 --- a/lightningd/test/run-invoice-select-inchan.c +++ b/lightningd/test/run-invoice-select-inchan.c @@ -382,7 +382,7 @@ void set_log_outfn_(struct log_book *lr UNNEEDED, bool continued UNNEEDED, const struct timeabs *time UNNEEDED, const char *str UNNEEDED, - const u8 *io UNNEEDED, + const u8 *io UNNEEDED, size_t io_len UNNEEDED, void *arg) UNNEEDED, void *arg UNNEEDED) { fprintf(stderr, "set_log_outfn_ called!\n"); abort(); } diff --git a/tests/test_gossip.py b/tests/test_gossip.py index cd123ab3de3a..220fb4344d04 100644 --- a/tests/test_gossip.py +++ b/tests/test_gossip.py @@ -1031,3 +1031,53 @@ def test_getroute_exclude(node_factory, bitcoind): # This doesn't with pytest.raises(RpcError): l1.rpc.getroute(l4.info['id'], 1, 1, exclude=[chan_l2l3, chan_l2l4]) + + +@unittest.skipIf(not DEVELOPER, "need dev-compact-gossip-store") +def test_gossip_store_local_channels(node_factory, bitcoind): + l1, l2 = node_factory.line_graph(2, wait_for_announce=False) + + # We see this channel, even though it's not announced, because it's local. + wait_for(lambda: len(l1.rpc.listchannels()['channels']) == 2) + + l2.stop() + l1.restart() + + # We should still see local channels! + time.sleep(3) # Make sure store is loaded + chans = l1.rpc.listchannels()['channels'] + assert len(chans) == 2 + + # Now compact store + l1.rpc.call('dev-compact-gossip-store') + l1.restart() + + time.sleep(3) # Make sure store is loaded + # We should still see local channels! + chans = l1.rpc.listchannels()['channels'] + assert len(chans) == 2 + + +@unittest.skipIf(not DEVELOPER, "need dev-compact-gossip-store") +def test_gossip_store_private_channels(node_factory, bitcoind): + l1, l2 = node_factory.line_graph(2, announce_channels=False) + + # We see this channel, even though it's not announced, because it's local. + wait_for(lambda: len(l1.rpc.listchannels()['channels']) == 2) + + l2.stop() + l1.restart() + + # We should still see local channels! + time.sleep(3) # Make sure store is loaded + chans = l1.rpc.listchannels()['channels'] + assert len(chans) == 2 + + # Now compact store + l1.rpc.call('dev-compact-gossip-store') + l1.restart() + + time.sleep(3) # Make sure store is loaded + # We should still see local channels! + chans = l1.rpc.listchannels()['channels'] + assert len(chans) == 2 diff --git a/tools/bench-gossipd.sh b/tools/bench-gossipd.sh new file mode 100755 index 000000000000..b3b45cffaad0 --- /dev/null +++ b/tools/bench-gossipd.sh @@ -0,0 +1,175 @@ +#! /bin/sh +# Needs bitcoind -regtest running. + +set -e + +DIR="" +TARGETS="" +DEFAULT_TARGETS=" store_load_msec vsz_kb store_rewrite_sec listnodes_sec listchannels_sec routing_sec peer_write_all_sec peer_read_all_sec " +MCP_DIR=../million-channels-project/data/1M/gossip/ +CSV=false + +wait_for_start() +{ + i=0 + ID="" + while [ -z "$ID" ]; do + ID="$($LCLI1 -H getinfo 2>/dev/null | grep '^id=' | cut -d= -f2)" + sleep 1 + i=$((i + 1)) + if [ $i = 10 ]; then + echo "lightningd didn't start?" >&2 + cat "$DIR"/log + exit 1 + fi + done + echo "$ID" +} + +print_stat() +{ + if $CSV; then + sed -e 's/^ *//' -e 's/ *$//' | tr \\012 , + else + echo "$1": | tr -d \\n + sed -e 's/^ *//' -e 's/ *$//' + fi +} + +for arg; do + case "$arg" in + --dir=*) + DIR="${arg#*=}" + ;; + --mcp-dir=*) + MCP_DIR="${arg#*=}" + ;; + --csv) + CSV=true + ;; + --help) + echo "Usage: tools/bench-gossipd.sh [--dir=] [--mcp-dir=] [--csv] [TARGETS]" + echo "Default targets:$DEFAULT_TARGETS" + exit 0 + ;; + -*) + echo "Unknown arg $arg" >&2 + exit 1 + ;; + *) + TARGETS="$TARGETS $arg" + ;; + esac +done + +# Targets must be space-separated for ## trick. +if [ -z "$TARGETS" ]; then + TARGETS="$DEFAULT_TARGETS" +else + TARGETS="$TARGETS " +fi + +if ! bitcoin-cli -regtest ping >/dev/null 2>&1; then + bitcoind -regtest > "$DIR"/bitcoind.log & + + while ! bitcoin-cli -regtest ping >/dev/null 2>&1; do sleep 1; done +fi + +LIGHTNINGD="./lightningd/lightningd --network=regtest --dev-gossip-time=1550513768 --dev-unknown-channel-satoshis=100000" +LCLI1="./cli/lightning-cli --lightning-dir=$DIR" + +if [ -z "$DIR" ]; then + trap 'rm -rf "$DIR"' 0 + + DIR="$(mktemp -d)" + ./devtools/create-gossipstore 100000 -i "$MCP_DIR"/1M.gossip -o "$DIR"/gossip_store +fi + +# shellcheck disable=SC2086 +if $CSV; then echo $TARGETS | tr ' ' ,; fi + +# First, measure load time. +rm -f "$DIR"/log "$DIR"/peer +$LIGHTNINGD --lightning-dir="$DIR" --log-file="$DIR"/log --bind-addr="$DIR"/peer & + +rm -f "$DIR"/stats +ID=$(wait_for_start) + +while ! grep -q 'gossipd.*: total store load time' "$DIR"/log 2>/dev/null; do + sleep 1 +done +if [ -z "${TARGETS##* store_load_msec *}" ]; then + grep 'gossipd.*: total store load time' "$DIR"/log | cut -d\ -f7 | print_stat store_load_msec +fi + +# How big is gossipd? +if [ -z "${TARGETS##* vsz_kb *}" ]; then + ps -o vsz= -p "$(pidof lightning_gossipd)" | print_stat vsz_kb +fi + +# How long does rewriting the store take? +if [ -z "${TARGETS##* store_rewrite_sec *}" ]; then + # shellcheck disable=SC2086 + /usr/bin/time --append -f %e $LCLI1 dev-compact-gossip-store 2>&1 > /dev/null | print_stat store_rewrite_sec +fi + +# Now, how long does listnodes take? +if [ -z "${TARGETS##* listnodes_sec *}" ]; then + # shellcheck disable=SC2086 + /usr/bin/time --append -f %e $LCLI1 listnodes 2>&1 > "$DIR"/listnodes.json | print_stat listnodes_sec +fi + +# Now, how long does listchannels take? +if [ -z "${TARGETS##* listchannels_sec *}" ]; then + # shellcheck disable=SC2086 + /usr/bin/time --append -f %e $LCLI1 listchannels 2>&1 > "$DIR"/listchannels.json | print_stat listchannels_sec +fi + +# Now, try routing between first and last points. +if [ -z "${TARGETS##* routing_sec *}" ]; then + echo "$DIV" | tr -d \\n; DIV="," + # shellcheck disable=SC2046 + # shellcheck disable=SC2005 + echo $(grep nodeid "$DIR"/listnodes.json | cut -d'"' -f4 | sort | head -n2) | while read -r from to; do + # shellcheck disable=SC2086 + /usr/bin/time --quiet --append -f %e $LCLI1 getroute $from 1 1 6 $to 2>&1 > /dev/null | print_stat routing_sec # FIXME: this shouldn't fail + done +fi + +# Try getting all from the peer. +if [ -z "${TARGETS##* peer_write_all_sec *}" ]; then + ENTRIES=$(sed -n 's/.*gossipd.*: total store load time: [0-9]* msec (\([0-9]*\) entries, [0-9]* bytes)/\1/p' < "$DIR"/log) + + /usr/bin/time --quiet --append -f %e devtools/gossipwith --initial-sync --max-messages=$((ENTRIES - 5)) "$ID"@"$DIR"/peer 2>&1 > /dev/null | print_stat peer_write_all_sec +fi + +if [ -z "${TARGETS##* peer_read_all_sec *}" ]; then + # shellcheck disable=SC2086 + $LCLI1 stop > /dev/null + sleep 5 + # In case they specified dir, don't blow away store. + mv "$DIR"/gossip_store "$DIR"/gossip_store.bak + rm -f "$DIR"/peer + + $LIGHTNINGD --lightning-dir="$DIR" --log-file="$DIR"/log --bind-addr="$DIR"/peer --log-level=debug & + ID=$(wait_for_start) + + # FIXME: Measure this better. + EXPECTED=$(find "$DIR"/gossip_store.bak -printf %s) + + START_TIME=$(date +%s) + # We send a bad msg at the end, so lightningd hangs up + xzcat ../million-channels-project/data/1M/gossip/xa*.xz | devtools/gossipwith --max-messages=1 --stdin "$ID"@"$DIR"/peer 0011 > /dev/null + + while [ "$(find "$DIR"/gossip_store -printf %s)" -lt "$EXPECTED" ]; do + sleep 1 + i=$((i + 1)) + done + END_TIME=$(date +%s) + + echo $((END_TIME - START_TIME)) | print_stat peer_read_all_sec + mv "$DIR"/gossip_store.bak "$DIR"/gossip_store +fi + +# shellcheck disable=SC2086 +$LCLI1 stop > /dev/null diff --git a/tools/check-includes.sh b/tools/check-includes.sh index 9be58bd21a46..18c9f2e17908 100755 --- a/tools/check-includes.sh +++ b/tools/check-includes.sh @@ -9,7 +9,7 @@ HEADER_ID_SUFFIX="_H" REGEXP_EXCLUDE_FILES_WITH_PREFIX="ccan/" for HEADER_FILE in $(git ls-files -- "*.h" | grep -vE "^${REGEXP_EXCLUDE_FILES_WITH_PREFIX}") do - HEADER_ID_BASE=$(tr / _ <<< "${HEADER_FILE/%.h/}" | tr "[:lower:]" "[:upper:]") + HEADER_ID_BASE=$(tr /- _ <<< "${HEADER_FILE/%.h/}" | tr "[:lower:]" "[:upper:]") HEADER_ID="${HEADER_ID_PREFIX}${HEADER_ID_BASE}${HEADER_ID_SUFFIX}" if [[ $(grep -cE "^#((ifndef|define) ${HEADER_ID}|endif /\\* ${HEADER_ID} \\*/)$" "${HEADER_FILE}") != 3 ]]; then echo "${HEADER_FILE} seems to be missing the expected include guard:" diff --git a/wallet/test/run-wallet.c b/wallet/test/run-wallet.c index 250a6b071d86..423f7c75467d 100644 --- a/wallet/test/run-wallet.c +++ b/wallet/test/run-wallet.c @@ -620,6 +620,7 @@ void set_log_outfn_(struct log_book *lr UNNEEDED, const struct timeabs *time UNNEEDED, const char *str UNNEEDED, const u8 *io UNNEEDED, + size_t io_len UNNEEDED, void *arg) UNNEEDED, void *arg UNNEEDED) { diff --git a/wire/wire_io.h b/wire/wire_io.h index 156b46de8189..2cdb537eea1c 100644 --- a/wire/wire_io.h +++ b/wire/wire_io.h @@ -6,7 +6,8 @@ #include /* We don't allow > 64M msgs: enough for 483 64k failure msgs. */ -#define WIRE_LEN_LIMIT (1 << 26) +/* FIXME: Too big, but allows the million-channels project at 327077670 bytes */ +#define WIRE_LEN_LIMIT (1 << 29) typedef be32 wire_len_t; #define wirelen_to_cpu be32_to_cpu