diff --git a/connectd/connectd.c b/connectd/connectd.c index d7a2d2340..7352feb80 100644 --- a/connectd/connectd.c +++ b/connectd/connectd.c @@ -2420,6 +2420,7 @@ static struct io_plan *recv_req(struct io_conn *conn, case WIRE_CONNECTD_START_SHUTDOWN_REPLY: case WIRE_CONNECTD_INJECT_ONIONMSG_REPLY: case WIRE_CONNECTD_ONIONMSG_FORWARD_FAIL: + case WIRE_CONNECTD_PING_LATENCY: break; } diff --git a/connectd/connectd.h b/connectd/connectd.h index 7da8a71c4..b6ab7a41f 100644 --- a/connectd/connectd.h +++ b/connectd/connectd.h @@ -96,6 +96,9 @@ struct peer { enum pong_expect_type expecting_pong; u64 ping_reqid; + /* Timestamp when we initially sent probe ping */ + struct timemono ping_start; + /* Random ping timer, to detect dead connections. */ struct oneshot *ping_timer; diff --git a/connectd/connectd_wire.csv b/connectd/connectd_wire.csv index c70b901e2..913482dad 100644 --- a/connectd/connectd_wire.csv +++ b/connectd/connectd_wire.csv @@ -156,6 +156,11 @@ msgdata,connectd_ping_done,sent,bool, # 0 == no pong expected, otherwise length of pong. msgdata,connectd_ping_done,totlen,u16, +# We give lightningd stats about ping latencies +msgtype,connectd_ping_latency,2038 +msgdata,connectd_ping_latency,id,node_id, +msgdata,connectd_ping_latency,ping_nsec,u64, + # We tell lightningd we got an onionmsg msgtype,connectd_got_onionmsg_to_us,2145 msgdata,connectd_got_onionmsg_to_us,path_secret,?secret, diff --git a/connectd/multiplex.c b/connectd/multiplex.c index b657a693a..2778a22ff 100644 --- a/connectd/multiplex.c +++ b/connectd/multiplex.c @@ -645,6 +645,7 @@ static void send_ping(struct peer *peer) } inject_peer_msg(peer, take(make_ping(NULL, 1, 0))); + peer->ping_start = time_mono(); peer->expecting_pong = PONG_EXPECTED_PROBING; } @@ -719,6 +720,10 @@ static void handle_pong_in(struct peer *peer, const u8 *msg) /* fall thru */ case PONG_EXPECTED_PROBING: peer->expecting_pong = PONG_UNEXPECTED; + daemon_conn_send(peer->daemon->master, + take(towire_connectd_ping_latency(NULL, + &peer->id, + time_to_nsec(timemono_since(peer->ping_start))))); return; case PONG_UNEXPECTED: status_debug("Unexpected pong?"); @@ -1532,6 +1537,7 @@ void send_manual_ping(struct daemon *daemon, const u8 *msg) if (tal_count(ping) > 65535) status_failed(STATUS_FAIL_MASTER_IO, "Oversize ping"); + peer->ping_start = time_mono(); inject_peer_msg(peer, take(ping)); status_debug("sending ping expecting %sresponse", diff --git a/lightningd/connect_control.c b/lightningd/connect_control.c index 74aef56c5..8766009b9 100644 --- a/lightningd/connect_control.c +++ b/lightningd/connect_control.c @@ -472,6 +472,21 @@ void tell_connectd_peer_importance(struct peer *peer, } } +static void handle_ping_latency(struct lightningd *ld, const u8 *msg) +{ + struct node_id id; + u64 nsec; + + if (!fromwire_connectd_ping_latency(msg, &id, &nsec)) { + log_broken(ld->log, "Malformed ping_latency: %s", + tal_hex(tmpctx, msg)); + return; + } + + log_peer_trace(ld->log, &id, "Ping latency: %"PRIu64"nsec", + nsec); +} + static unsigned connectd_msg(struct subd *connectd, const u8 *msg, const int *fds) { enum connectd_wire t = fromwire_peektype(msg); @@ -537,6 +552,10 @@ static unsigned connectd_msg(struct subd *connectd, const u8 *msg, const int *fd case WIRE_CONNECTD_PING_DONE: handle_ping_done(connectd, msg); break; + + case WIRE_CONNECTD_PING_LATENCY: + handle_ping_latency(connectd->ld, msg); + break; } return 0; }