connectd: return reason, connect time to lightningd on connection results.

diff --git a/connectd/connectd.c b/connectd/connectd.c
index c6e06a58..d7a2d234 100644
--- a/connectd/connectd.c
+++ b/connectd/connectd.c
@@ -76,7 +76,8 @@ static void try_connect_one_addr(struct connecting *connect);
  * timer to call a higher function again, so has to be pre-declared. */
 static void try_connect_peer(struct daemon *daemon,
 			     const struct node_id *id,
-			     struct wireaddr_internal *addrs TAKES);
+			     struct wireaddr_internal *addrs TAKES,
+			     const char *reason);
 
 /* We track peers which are important, and try to reconnect (with backoff) */
 static void schedule_reconnect_if_important(struct daemon *daemon,
@@ -290,6 +291,8 @@ struct io_plan *peer_connected(struct io_conn *conn,
 	int subd_fd;
 	bool option_gossip_queries;
 	struct connecting *connect;
+	const char *connect_reason;
+	u64 connect_time_nsec;
 	u64 prev_connectd_counter;
 
 	/* We remove any previous connection immediately, on the assumption it's dead */
@@ -358,7 +361,16 @@ struct io_plan *peer_connected(struct io_conn *conn,
 		 * in progress right now) */
 		if (connect->conn)
 			io_set_finish(connect->conn, NULL, NULL);
+		if (incoming)
+			connect_reason = "incoming connection while trying to connect";
+		else
+			connect_reason = tal_steal(tmpctx, connect->reason);
+		connect_time_nsec = time_to_nsec(timemono_since(connect->start));
 		tal_free(connect);
+	} else {
+		assert(incoming);
+		connect_reason = "incoming connection";
+		connect_time_nsec = 0;
 	}
 
 	/* This contains the per-peer state info; gossipd fills in pps->gs */
@@ -394,7 +406,9 @@ struct io_plan *peer_connected(struct io_conn *conn,
 
 		msg = towire_connectd_peer_connected(NULL, id, peer->counter,
 						     addr, remote_addr,
-						     incoming, their_features);
+						     incoming, their_features,
+						     connect_reason,
+						     connect_time_nsec);
 	}
 
 	/*~ daemon_conn is a message queue for inter-daemon communication: we
@@ -761,9 +775,11 @@ struct io_plan *connection_out(struct io_conn *conn, struct connecting *connect)
  */
 static void connect_failed(struct daemon *daemon,
 			   const struct node_id *id,
+			   const char *connect_reason,
+			   struct timemono start,
 			   enum jsonrpc_errcode errcode,
 			   const char *errfmt, ...)
-	PRINTF_FMT(4,5);
+	PRINTF_FMT(6, 7);
 
 static void reconnect(struct important_id *imp)
 {
@@ -775,7 +791,8 @@ static void reconnect(struct important_id *imp)
 	append_gossmap_addresses(&addrs, imp->daemon, &imp->id);
 
 	imp->reconnect_timer = NULL;
-	try_connect_peer(imp->daemon, &imp->id, take(addrs));
+	try_connect_peer(imp->daemon, &imp->id, take(addrs),
+			 "reconnect by timer");
 }
 
 static void schedule_reconnect_if_important(struct daemon *daemon,
@@ -825,6 +842,7 @@ void release_one_waiting_connection(struct daemon *daemon, const char *why)
 		if (c->waiting) {
 			status_peer_debug(&c->id, "Unblocking for %s", why);
 			c->waiting = false;
+			c->start = time_mono();
 			try_connect_one_addr(c);
 			break;
 		}
@@ -833,6 +851,8 @@ void release_one_waiting_connection(struct daemon *daemon, const char *why)
 
 static void connect_failed(struct daemon *daemon,
 			   const struct node_id *id,
+			   const char *connect_reason,
+			   struct timemono start,
 			   enum jsonrpc_errcode errcode,
 			   const char *errfmt, ...)
 {
@@ -848,7 +868,10 @@ static void connect_failed(struct daemon *daemon,
 
 	/* lightningd may have a connect command waiting to know what
 	 * happened. */
-	msg = towire_connectd_connect_failed(NULL, id, errcode, errmsg);
+	msg = towire_connectd_connect_failed(NULL, id,
+					     connect_reason,
+					     time_to_nsec(timemono_since(start)),
+					     errcode, errmsg);
 	daemon_conn_send(daemon->master, take(msg));
 
 	/* If we're supposed to schedule a reconnect, do so */
@@ -999,9 +1022,11 @@ static void try_connect_one_addr(struct connecting *connect)
 		struct daemon *daemon = connect->daemon;
 		struct node_id id = connect->id;
 		const char *errors = tal_steal(tmpctx, connect->errors);
+		const char *reason = tal_steal(tmpctx, connect->reason);
+		struct timemono start = connect->start;
 
 		tal_free(connect);
-		connect_failed(daemon, &id,
+		connect_failed(daemon, &id, reason, start,
 			       CONNECT_ALL_ADDRESSES_FAILED,
 			       "All addresses failed: %s",
 			       errors);
@@ -1784,7 +1809,8 @@ static bool addr_in(const struct wireaddr_internal *needle,
 /*~ Try to connect to a single peer, given some addresses (in order) */
 static void try_connect_peer(struct daemon *daemon,
 			     const struct node_id *id,
-			     struct wireaddr_internal *addrs TAKES)
+			     struct wireaddr_internal *addrs TAKES,
+			     const char *reason TAKES)
 {
 	bool use_proxy = daemon->always_use_proxy;
 	struct connecting *connect;
@@ -1793,6 +1819,8 @@ static void try_connect_peer(struct daemon *daemon,
 	/* In case we return without using it, make sure it's freed. */
 	if (taken(addrs))
 		tal_steal(tmpctx, addrs);
+	if (taken(reason))
+		tal_steal(tmpctx, reason);
 
 	/* Already existing?  Must have crossed over, it'll know soon. */
 	peer = peer_htable_get(daemon->peers, id);
@@ -1831,7 +1859,7 @@ static void try_connect_peer(struct daemon *daemon,
 	/* Still no address?  Fail immediately.  Important ones get
 	 * retried; an address may get gossiped. */
 	if (tal_count(addrs) == 0) {
-		connect_failed(daemon, id,
+		connect_failed(daemon, id, reason, time_mono(),
 			       CONNECT_NO_KNOWN_ADDRESS,
 			       "Unable to connect, no address known for peer");
 		return;
@@ -1840,6 +1868,7 @@ static void try_connect_peer(struct daemon *daemon,
 	/* Start connecting to it: since this is the only place we allocate
 	 * a 'struct connecting' we don't write a separate new_connecting(). */
 	connect = tal(daemon, struct connecting);
+	connect->reason = tal_strdup(connect, reason);
 	connect->daemon = daemon;
 	connect->id = *id;
 	connect->addrs = tal_dup_talarr(connect, struct wireaddr_internal, addrs);
@@ -1859,8 +1888,10 @@ static void try_connect_peer(struct daemon *daemon,
 			    > daemon->max_connect_in_flight);
 	if (connect->waiting)
 		status_peer_debug(id, "Too many connections, waiting...");
-	else
+	else {
+		connect->start = time_mono();
 		try_connect_one_addr(connect);
+	}
 }
 
 static void destroy_important_id(struct important_id *imp)
@@ -1875,10 +1906,11 @@ static void connect_to_peer(struct daemon *daemon, const u8 *msg)
 	struct wireaddr_internal *addrs;
 	bool transient;
 	struct important_id *imp;
+	char *reason;
 
 	if (!fromwire_connectd_connect_to_peer(tmpctx, msg,
 					       &id, &addrs,
-					       &transient))
+					       &transient, &reason))
 		master_badmsg(WIRE_CONNECTD_CONNECT_TO_PEER, msg);
 
 	/* fromwire doesn't allocate empty arrays! */
@@ -1917,7 +1949,7 @@ static void connect_to_peer(struct daemon *daemon, const u8 *msg)
 	/* Do gossmap lookup to find any addresses from there, and append. */
 	append_gossmap_addresses(&addrs, daemon, &id);
 
-	try_connect_peer(daemon, &id, addrs);
+	try_connect_peer(daemon, &id, addrs, take(reason));
 }
 
 /* lightningd tells us a peer should be disconnected. */
diff --git a/connectd/connectd.h b/connectd/connectd.h
index 09778e2d..7da8a71c 100644
--- a/connectd/connectd.h
+++ b/connectd/connectd.h
@@ -203,6 +203,12 @@ struct connecting {
 	/* How far did we get? */
 	const char *connstate;
 
+	/* Why are we connecting? */
+	const char *reason;
+
+	/* When did we start? */
+	struct timemono start;
+
 	/* Accumulated errors */
 	char *errors;
 };
diff --git a/connectd/connectd_wire.csv b/connectd/connectd_wire.csv
index 78df85ef..c70b901e 100644
--- a/connectd/connectd_wire.csv
+++ b/connectd/connectd_wire.csv
@@ -64,10 +64,13 @@ msgdata,connectd_connect_to_peer,id,node_id,
 msgdata,connectd_connect_to_peer,len,u32,
 msgdata,connectd_connect_to_peer,addrs,wireaddr_internal,len
 msgdata,connectd_connect_to_peer,transient,bool,
+msgdata,connectd_connect_to_peer,reason,wirestring,
 
 # Connectd->master: connect failed.
 msgtype,connectd_connect_failed,2020
 msgdata,connectd_connect_failed,id,node_id,
+msgdata,connectd_connect_failed,connect_reason,wirestring,
+msgdata,connectd_connect_failed,connect_nsec,u64,
 msgdata,connectd_connect_failed,failcode,enum jsonrpc_errcode,
 msgdata,connectd_connect_failed,failreason,wirestring,
 
@@ -80,6 +83,8 @@ msgdata,connectd_peer_connected,remote_addr,?wireaddr,
 msgdata,connectd_peer_connected,incoming,bool,
 msgdata,connectd_peer_connected,flen,u16,
 msgdata,connectd_peer_connected,features,u8,flen
+msgdata,connectd_peer_connected,connect_reason,wirestring,
+msgdata,connectd_peer_connected,connect_nsec,u64,
 
 # connectd -> master: peer disconnected.
 msgtype,connectd_peer_disconnected,2006
diff --git a/lightningd/connect_control.c b/lightningd/connect_control.c
index d4268115..74aef56c 100644
--- a/lightningd/connect_control.c
+++ b/lightningd/connect_control.c
@@ -235,7 +235,9 @@ static struct command_result *json_connect(struct command *cmd,
 		peer_channels_cleanup(peer);
 
 	subd_send_msg(cmd->ld->connectd,
-		      take(towire_connectd_connect_to_peer(NULL, &id_addr.id, addr, true)));
+		      take(towire_connectd_connect_to_peer(NULL, &id_addr.id,
+							   addr, true,
+							   tal_fmt(tmpctx, "connect command %s", cmd->id))));
 
 	/* Leave this here for peer_connected, connect_failed or peer_disconnected. */
 	new_connect(cmd->ld, &id_addr.id, cmd);
@@ -252,6 +254,8 @@ AUTODATA(json_command, &connect_command);
 static void connect_failed(struct lightningd *ld,
 			   const struct node_id *id,
 			   const struct wireaddr_internal *addrhint,
+			   const char *connect_reason,
+			   u64 connect_nsec,
 			   enum jsonrpc_errcode errcode,
 			   const char *errmsg)
 {
@@ -268,7 +272,9 @@ void connect_failed_disconnect(struct lightningd *ld,
 			       const struct node_id *id,
 			       const struct wireaddr_internal *addrhint)
 {
-	connect_failed(ld, id, addrhint, CONNECT_DISCONNECTED_DURING,
+	connect_failed(ld, id, addrhint,
+		       "", 0,
+		       CONNECT_DISCONNECTED_DURING,
 		       "disconnected during connection");
 }
 
@@ -277,12 +283,17 @@ static void handle_connect_failed(struct lightningd *ld, const u8 *msg)
 	struct node_id id;
 	enum jsonrpc_errcode errcode;
 	char *errmsg;
+	char *connect_reason;
+	u64 nsec;
 
-	if (!fromwire_connectd_connect_failed(tmpctx, msg, &id, &errcode, &errmsg))
+	if (!fromwire_connectd_connect_failed(tmpctx, msg, &id,
+					      &connect_reason,
+					      &nsec,
+					      &errcode, &errmsg))
 		fatal("Connect gave bad CONNECTD_CONNECT_FAILED message %s",
 		      tal_hex(msg, msg));
 
-	connect_failed(ld, &id, NULL, errcode, errmsg);
+	connect_failed(ld, &id, NULL, connect_reason, nsec, errcode, errmsg);
 }
 
 const char *connect_any_cmd_id(const tal_t *ctx,
@@ -422,6 +433,7 @@ void connectd_start_shutdown(struct subd *connectd)
 
 void connectd_connect_to_peer(struct lightningd *ld,
 			      const struct peer *peer,
+			      const char *reason,
 			      bool is_important)
 {
 	/* Give connectd an address if we know it. */
@@ -435,7 +447,8 @@ void connectd_connect_to_peer(struct lightningd *ld,
 	subd_send_msg(peer->ld->connectd,
 		      take(towire_connectd_connect_to_peer(NULL, &peer->id,
 							   waddr,
-							   !is_important)));
+							   !is_important,
+							   reason)));
 }
 
 void tell_connectd_peer_importance(struct peer *peer,
@@ -453,7 +466,9 @@ void tell_connectd_peer_importance(struct peer *peer,
 	} else if (!was_important && is_important) {
 		/* Tell connectd it's now important (unless we're told not to reconnect) */
 		if (peer->ld->reconnect)
-			connectd_connect_to_peer(peer->ld, peer, true);
+			connectd_connect_to_peer(peer->ld, peer,
+						 "peer established channel",
+						 true);
 	}
 }
 
diff --git a/lightningd/connect_control.h b/lightningd/connect_control.h
index 47f14391..57b33790 100644
--- a/lightningd/connect_control.h
+++ b/lightningd/connect_control.h
@@ -18,6 +18,7 @@ void connectd_start_shutdown(struct subd *connectd);
 /* Tell connectd to connect to peer: give it what we know. */
 void connectd_connect_to_peer(struct lightningd *ld,
 			      const struct peer *peer,
+			      const char *reason,
 			      bool is_important);
 
 /* Kill subds, tell connectd to disconnect once they're drained. */
diff --git a/lightningd/gossip_control.c b/lightningd/gossip_control.c
index 6b484a77..0043de96 100644
--- a/lightningd/gossip_control.c
+++ b/lightningd/gossip_control.c
@@ -177,7 +177,8 @@ static void handle_connect_to_peer(struct subd *gossip, const u8 *msg)
 	connectmsg = towire_connectd_connect_to_peer(NULL,
 						     &id,
 						     NULL,	//addrhint,
-						     true);	//transient
+						     true,	//transient
+						     "gossipd");
 	subd_send_msg(gossip->ld->connectd, take(connectmsg));
 }
 
diff --git a/lightningd/peer_control.c b/lightningd/peer_control.c
index 59c06c4d..ae2f017d 100644
--- a/lightningd/peer_control.c
+++ b/lightningd/peer_control.c
@@ -1708,17 +1708,21 @@ void handle_peer_connected(struct lightningd *ld, const u8 *msg)
 	struct peer_connected_hook_payload *hook_payload;
 	u64 connectd_counter;
 	const char *cmd_id;
+	char *connect_reason;
+	u64 connect_nsec;
 	struct wireaddr *last_known_addr;
 
 	hook_payload = tal(NULL, struct peer_connected_hook_payload);
 	hook_payload->ld = ld;
 	hook_payload->error = NULL;
 	if (!fromwire_connectd_peer_connected(hook_payload, msg,
-					     &id, &connectd_counter,
-					     &hook_payload->addr,
-					     &hook_payload->remote_addr,
-					     &hook_payload->incoming,
-					     &their_features)) {
+					      &id, &connectd_counter,
+					      &hook_payload->addr,
+					      &hook_payload->remote_addr,
+					      &hook_payload->incoming,
+					      &their_features,
+					      &connect_reason,
+					      &connect_nsec)) {
 		u64 prev_connectd_counter;
 		if (!fromwire_connectd_peer_reconnected(hook_payload, msg,
 							&id, &prev_connectd_counter,
@@ -1734,6 +1738,8 @@ void handle_peer_connected(struct lightningd *ld, const u8 *msg)
 		 * fail any connect attempts: this is a race. */
 		log_peer_debug(ld->log, &id, "peer reconnected");
 		peer_disconnected(ld, &id, prev_connectd_counter, false);
+		connect_reason = tal_strdup(hook_payload, "");
+		connect_nsec = 0;
 	}
 
 	/* If we connected, and it's a normal address */
@@ -1809,6 +1815,8 @@ void handle_peer_connected(struct lightningd *ld, const u8 *msg)
 		}
 	}
 
+	/* Free connection reason string to keep memleak detection happy. */
+	tal_free(connect_reason);
 	plugin_hook_call_peer_connected(ld, cmd_id, hook_payload);
 }
 
@@ -2689,7 +2697,9 @@ static void setup_peer(struct peer *peer)
 	/* Make sure connectd knows to try reconnecting (unless
 	 * --dev-no-reconnect). */
 	if (connect && ld->reconnect)
-		connectd_connect_to_peer(ld, peer, important);
+		connectd_connect_to_peer(ld, peer,
+					 "started with channel",
+					 important);
 }
 
 void setup_peers(struct lightningd *ld)
diff --git a/lightningd/test/run-invoice-select-inchan.c b/lightningd/test/run-invoice-select-inchan.c
index 96dc1d61..3ed72c70 100644
--- a/lightningd/test/run-invoice-select-inchan.c
+++ b/lightningd/test/run-invoice-select-inchan.c
@@ -218,6 +218,7 @@ void connect_succeeded(struct lightningd *ld UNNEEDED, const struct peer *peer U
 /* Generated stub for connectd_connect_to_peer */
 void connectd_connect_to_peer(struct lightningd *ld UNNEEDED,
 			      const struct peer *peer UNNEEDED,
+			      const char *reason UNNEEDED,
 			      bool is_important UNNEEDED)
 { fprintf(stderr, "connectd_connect_to_peer called!\n"); abort(); }
 /* Generated stub for create_anchor_details */
@@ -269,7 +270,7 @@ void force_peer_disconnect(struct lightningd *ld UNNEEDED,
 bool fromwire_channeld_dev_memleak_reply(const void *p UNNEEDED, bool *leak UNNEEDED)
 { fprintf(stderr, "fromwire_channeld_dev_memleak_reply called!\n"); abort(); }
 /* Generated stub for fromwire_connectd_peer_connected */
-bool fromwire_connectd_peer_connected(const tal_t *ctx UNNEEDED, const void *p UNNEEDED, struct node_id *id UNNEEDED, u64 *counter UNNEEDED, struct wireaddr_internal *addr UNNEEDED, struct wireaddr **remote_addr UNNEEDED, bool *incoming UNNEEDED, u8 **features UNNEEDED)
+bool fromwire_connectd_peer_connected(const tal_t *ctx UNNEEDED, const void *p UNNEEDED, struct node_id *id UNNEEDED, u64 *counter UNNEEDED, struct wireaddr_internal *addr UNNEEDED, struct wireaddr **remote_addr UNNEEDED, bool *incoming UNNEEDED, u8 **features UNNEEDED, wirestring **connect_reason UNNEEDED, u64 *connect_nsec UNNEEDED)
 { fprintf(stderr, "fromwire_connectd_peer_connected called!\n"); abort(); }
 /* Generated stub for fromwire_connectd_peer_disconnected */
 bool fromwire_connectd_peer_disconnected(const void *p UNNEEDED, struct node_id *id UNNEEDED, u64 *counter UNNEEDED)
diff --git a/wallet/test/run-wallet.c b/wallet/test/run-wallet.c
index 5ce78e71..54f0a385 100644
--- a/wallet/test/run-wallet.c
+++ b/wallet/test/run-wallet.c
@@ -213,6 +213,7 @@ void connect_succeeded(struct lightningd *ld UNNEEDED, const struct peer *peer U
 /* Generated stub for connectd_connect_to_peer */
 void connectd_connect_to_peer(struct lightningd *ld UNNEEDED,
 			      const struct peer *peer UNNEEDED,
+			      const char *reason UNNEEDED,
 			      bool is_important UNNEEDED)
 { fprintf(stderr, "connectd_connect_to_peer called!\n"); abort(); }
 /* Generated stub for create_anchor_details */
@@ -298,7 +299,7 @@ bool fromwire_channeld_offer_htlc_reply(const tal_t *ctx UNNEEDED, const void *p
 bool fromwire_channeld_sending_commitsig(const tal_t *ctx UNNEEDED, const void *p UNNEEDED, u64 *commitnum UNNEEDED, struct penalty_base **pbase UNNEEDED, struct fee_states **fee_states UNNEEDED, struct height_states **blockheight_states UNNEEDED, struct changed_htlc **changed UNNEEDED)
 { fprintf(stderr, "fromwire_channeld_sending_commitsig called!\n"); abort(); }
 /* Generated stub for fromwire_connectd_peer_connected */
-bool fromwire_connectd_peer_connected(const tal_t *ctx UNNEEDED, const void *p UNNEEDED, struct node_id *id UNNEEDED, u64 *counter UNNEEDED, struct wireaddr_internal *addr UNNEEDED, struct wireaddr **remote_addr UNNEEDED, bool *incoming UNNEEDED, u8 **features UNNEEDED)
+bool fromwire_connectd_peer_connected(const tal_t *ctx UNNEEDED, const void *p UNNEEDED, struct node_id *id UNNEEDED, u64 *counter UNNEEDED, struct wireaddr_internal *addr UNNEEDED, struct wireaddr **remote_addr UNNEEDED, bool *incoming UNNEEDED, u8 **features UNNEEDED, wirestring **connect_reason UNNEEDED, u64 *connect_nsec UNNEEDED)
 { fprintf(stderr, "fromwire_connectd_peer_connected called!\n"); abort(); }
 /* Generated stub for fromwire_connectd_peer_disconnected */
 bool fromwire_connectd_peer_disconnected(const void *p UNNEEDED, struct node_id *id UNNEEDED, u64 *counter UNNEEDED)