Add the time we received and resolved a forwarding to listforwards

CHANGELOG.md

@@ -11,6 +11,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 - JSON API: `newaddr` outputs `bech32` or `p2sh-segwit`, or both with new `all` parameter (#2390)
 - JSON API: `listpeers` status now shows how many confirmations until channel is open (#2405)
 - Config: Adds parameter `min-capacity-sat` to reject tiny channels.
+- JSON API: `listforwards` now includes the time an HTLC was received and when it was resolved. Both are expressed as UNIX timestamps to facilitate parsing (Issue [#2491](https:/ElementsProject/lightning/issues/2491), PR [#2528](https:/ElementsProject/lightning/pull/2528))
 
 ### Changed
 

Makefile

@@ -47,7 +47,7 @@ endif
 
 ifeq ($(COMPAT),1)
 # We support compatibility with pre-0.6.
-COMPAT_CFLAGS=-DCOMPAT_V052=1 -DCOMPAT_V060=1 -DCOMPAT_V061=1 -DCOMPAT_V062=1
+COMPAT_CFLAGS=-DCOMPAT_V052=1 -DCOMPAT_V060=1 -DCOMPAT_V061=1 -DCOMPAT_V062=1 -DCOMPAT_V070=1
 endif
 
 # Timeout shortly before the 600 second travis silence timeout

lightningd/htlc_end.c

@@ -134,6 +134,8 @@ struct htlc_in *new_htlc_in(const tal_t *ctx,
  hin->failuremsg = NULL;
  hin->preimage = NULL;
 
+ hin->received_time = time_now();
+
  return htlc_in_check(hin, "new_htlc_in");
 }
 

lightningd/htlc_end.h

@@ -3,6 +3,7 @@
 #include "config.h"
 #include <ccan/htable/htable_type.h>
 #include <ccan/short_types/short_types.h>
+#include <ccan/time/time.h>
 #include <common/amount.h>
 #include <common/htlc_state.h>
 #include <common/sphinx.h>
@@ -47,6 +48,9 @@ struct htlc_in {
  /* If they fulfilled, here's the preimage. */
  struct preimage *preimage;
 
+ /* Remember the timestamp we received this HTLC so we can later record
+ * it, and the resolution time, in the forwards table. */
+ struct timeabs received_time;
 };
 
 struct htlc_out {

lightningd/json.c

@@ -351,3 +351,10 @@ void json_add_amount_sat(struct json_stream *result,
  json_add_member(result, msatfieldname, "\"%s\"",
  type_to_string(tmpctx, struct amount_msat, &msat));
 }
+
+void json_add_timeabs(struct json_stream *result, const char *fieldname,
+ struct timeabs t)
+{
+ json_add_member(result, fieldname, "%" PRIu64 ".%03" PRIu64,
+ (u64)t.ts.tv_sec, (u64)t.ts.tv_nsec / 1000000);
+}

lightningd/json.h

@@ -7,6 +7,7 @@
 #include "config.h"
 #include <ccan/short_types/short_types.h>
 #include <ccan/tal/tal.h>
+#include <ccan/time/time.h>
 #include <common/amount.h>
 #include <stdbool.h>
 #include <stddef.h>
@@ -157,4 +158,8 @@ enum address_parse_result json_tok_address_scriptpubkey(const tal_t *ctx,
  const struct chainparams *chainparams,
  const char *buffer,
  const jsmntok_t *tok, const u8 **scriptpubkey);
+
+void json_add_timeabs(struct json_stream *result, const char *fieldname,
+ struct timeabs t);
+
 #endif /* LIGHTNING_LIGHTNINGD_JSON_H */

lightningd/peer_htlcs.c

@@ -1902,6 +1902,19 @@ static void listforwardings_add_forwardings(struct json_stream *response, struct
  cur->fee,
  "fee", "fee_msat");
  json_add_string(response, "status", forward_status_name(cur->status));
+#ifdef COMPAT_V070
+ /* If a forwarding doesn't have received_time it was created
+ * before we added the tracking, do not include it here. */
+ if (cur->received_time.ts.tv_sec) {
+ json_add_timeabs(response, "received_time", cur->received_time);
+ if (cur->resolved_time)
+ json_add_timeabs(response, "resolved_time", *cur->resolved_time);
+ }
+#else
+ json_add_timeabs(response, "received_time", cur->received_time);
+ if (cur->resolved_time)
+ json_add_timeabs(response, "resolved_time", *cur->resolved_time);
+#endif
  json_object_end(response);
  }
  json_array_end(response);

tests/test_pay.py

@@ -1052,7 +1052,7 @@ def test_forward_stats(node_factory, bitcoind):
 
  We wire up the network to have l1 as payment initiator, l2 as
  forwarded (the one we check) and l3-l5 as payment recipients. l3
- accepts correctly, l4 refects (because it doesn't know the payment
+ accepts correctly, l4 rejects (because it doesn't know the payment
  hash) and l5 will keep the HTLC dangling by disconnecting.
 
  """
@@ -1119,6 +1119,9 @@ def test_forward_stats(node_factory, bitcoind):
  assert l2.rpc.getinfo()['msatoshi_fees_collected'] == 1 + amount // 100000
  assert l1.rpc.getinfo()['msatoshi_fees_collected'] == 0
  assert l3.rpc.getinfo()['msatoshi_fees_collected'] == 0
+ assert stats['forwards'][0]['received_time'] <= stats['forwards'][0]['resolved_time']
+ assert stats['forwards'][1]['received_time'] <= stats['forwards'][1]['resolved_time']
+ assert 'received_time' in stats['forwards'][2] and 'resolved_time' not in stats['forwards'][2]
 
 
 @unittest.skipIf(not DEVELOPER or SLOW_MACHINE, "needs DEVELOPER=1 for dev_ignore_htlcs, and temporarily disabled on Travis")

wallet/db.c

@@ -10,6 +10,7 @@
 #include <lightningd/plugin_hook.h>
 
 #define DB_FILE "lightningd.sqlite3"
+#define NSEC_IN_SEC 1000000000
 
 /* For testing, we want to catch fatal messages. */
 #ifndef db_fatal
@@ -374,6 +375,9 @@ static struct migration dbmigrations[] = {
  { "ALTER TABLE channels ADD feerate_base INTEGER;", NULL },
  { "ALTER TABLE channels ADD feerate_ppm INTEGER;", NULL },
  { NULL, migrate_pr2342_feerate_per_channel },
+ { "ALTER TABLE channel_htlcs ADD received_time INTEGER", NULL },
+ { "ALTER TABLE forwarded_payments ADD received_time INTEGER", NULL },
+ { "ALTER TABLE forwarded_payments ADD resolved_time INTEGER", NULL },
 };
 
 /* Leak tracking. */
@@ -1090,3 +1094,19 @@ void migrate_pr2342_feerate_per_channel(struct lightningd *ld, struct db *db)
  ld->config.fee_base,
  ld->config.fee_per_satoshi);
 }
+
+void sqlite3_bind_timeabs(sqlite3_stmt *stmt, int col, struct timeabs t)
+{
+ u64 timestamp = t.ts.tv_nsec + (t.ts.tv_sec * NSEC_IN_SEC);
+ sqlite3_bind_int64(stmt, col, timestamp);
+}
+
+struct timeabs sqlite3_column_timeabs(sqlite3_stmt *stmt, int col)
+{
+ struct timeabs t;
+ u64 timestamp = sqlite3_column_int64(stmt, col);
+ t.ts.tv_sec = timestamp / NSEC_IN_SEC;
+ t.ts.tv_nsec = timestamp % NSEC_IN_SEC;
+ return t;
+
+}

wallet/db.h

@@ -8,6 +8,7 @@
 #include <bitcoin/tx.h>
 #include <ccan/short_types/short_types.h>
 #include <ccan/tal/tal.h>
+#include <ccan/time/time.h>
 #include <common/amount.h>
 #include <secp256k1_ecdh.h>
 #include <sqlite3.h>
@@ -203,4 +204,9 @@ void sqlite3_bind_amount_msat(sqlite3_stmt *stmt, int col,
  struct amount_msat msat);
 void sqlite3_bind_amount_sat(sqlite3_stmt *stmt, int col,
  struct amount_sat sat);
+
+/* Helpers to read and write absolute times from and to the database. */
+void sqlite3_bind_timeabs(sqlite3_stmt *stmt, int col, struct timeabs t);
+struct timeabs sqlite3_column_timeabs(sqlite3_stmt *stmt, int col);
+
 #endif /* LIGHTNING_WALLET_DB_H */

wallet/test/run-wallet.c

@@ -251,6 +251,10 @@ void json_add_short_channel_id(struct json_stream *response UNNEEDED,
 /* Generated stub for json_add_string */
 void json_add_string(struct json_stream *result UNNEEDED, const char *fieldname UNNEEDED, const char *value UNNEEDED)
 { fprintf(stderr, "json_add_string called!\n"); abort(); }
+/* Generated stub for json_add_timeabs */
+void json_add_timeabs(struct json_stream *result UNNEEDED, const char *fieldname UNNEEDED,
+ struct timeabs t UNNEEDED)
+{ fprintf(stderr, "json_add_timeabs called!\n"); abort(); }
 /* Generated stub for json_add_txid */
 void json_add_txid(struct json_stream *result UNNEEDED, const char *fieldname UNNEEDED,
  const struct bitcoin_txid *txid UNNEEDED)

wallet/wallet.c

@@ -1233,8 +1233,9 @@ void wallet_htlc_save_in(struct wallet *wallet,
  " payment_key,"
  " hstate,"
  " shared_secret,"
- " routing_onion) VALUES "
- "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?);");
+ " routing_onion,"
+ " received_time) VALUES "
+ "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?);");
 
  sqlite3_bind_int64(stmt, 1, chan->dbid);
  sqlite3_bind_int64(stmt, 2, in->key.id);
@@ -1258,6 +1259,8 @@ void wallet_htlc_save_in(struct wallet *wallet,
  sqlite3_bind_blob(stmt, 10, &in->onion_routing_packet,
  sizeof(in->onion_routing_packet), SQLITE_TRANSIENT);
 
+ sqlite3_bind_timeabs(stmt, 11, in->received_time);
+
  db_exec_prepared(wallet->db, stmt);
  in->dbid = sqlite3_last_insert_rowid(wallet->db->sql);
 }
@@ -1351,7 +1354,7 @@ void wallet_htlc_update(struct wallet *wallet, const u64 htlc_dbid,
  "id, channel_htlc_id, msatoshi, cltv_expiry, hstate, " \
  "payment_hash, payment_key, routing_onion, " \
  "failuremsg, malformed_onion," \
- "origin_htlc, shared_secret"
+ "origin_htlc, shared_secret, received_time"
 
 static bool wallet_stmt2htlc_in(struct channel *channel,
  sqlite3_stmt *stmt, struct htlc_in *in)
@@ -1393,6 +1396,8 @@ static bool wallet_stmt2htlc_in(struct channel *channel,
 #endif
  }
 
+ in->received_time = sqlite3_column_timeabs(stmt, 12);
+
  return ok;
 }
 
@@ -2487,14 +2492,24 @@ void wallet_forwarded_payment_add(struct wallet *w, const struct htlc_in *in,
  ", out_channel_scid"
  ", in_msatoshi"
  ", out_msatoshi"
- ", state) VALUES (?, ?, ?, ?, ?, ?, ?);");
+ ", state"
+ ", received_time"
+ ", resolved_time"
+ ") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?);");
  sqlite3_bind_int64(stmt, 1, in->dbid);
  sqlite3_bind_int64(stmt, 2, out->dbid);
  sqlite3_bind_int64(stmt, 3, in->key.channel->scid->u64);
  sqlite3_bind_int64(stmt, 4, out->key.channel->scid->u64);
  sqlite3_bind_amount_msat(stmt, 5, in->msat);
  sqlite3_bind_amount_msat(stmt, 6, out->msat);
  sqlite3_bind_int(stmt, 7, wallet_forward_status_in_db(state));
+ sqlite3_bind_timeabs(stmt, 8, in->received_time);
+
+ if (state == FORWARD_SETTLED || state == FORWARD_FAILED)
+ sqlite3_bind_timeabs(stmt, 9, time_now());
+ else
+ sqlite3_bind_null(stmt, 9);
+
  db_exec_prepared(w->db, stmt);
 }
 
@@ -2532,7 +2547,9 @@ const struct forwarding *wallet_forwarded_payments_get(struct wallet *w,
  ", out_msatoshi"
  ", hin.payment_hash as payment_hash"
  ", in_channel_scid"
- ", out_channel_scid "
+ ", out_channel_scid"
+ ", f.received_time"
+ ", f.resolved_time "
  "FROM forwarded_payments f "
  "LEFT JOIN channel_htlcs hin ON (f.in_htlc_id == hin.id)");
 
@@ -2560,6 +2577,15 @@ const struct forwarding *wallet_forwarded_payments_get(struct wallet *w,
 
  cur->channel_in.u64 = sqlite3_column_int64(stmt, 4);
  cur->channel_out.u64 = sqlite3_column_int64(stmt, 5);
+
+ cur->received_time = sqlite3_column_timeabs(stmt, 6);
+ if (sqlite3_column_type(stmt, 7) != SQLITE_NULL) {
+ cur->resolved_time = tal(ctx, struct timeabs);
+ *cur->resolved_time = sqlite3_column_timeabs(stmt, 7);
+ } else {
+ cur->resolved_time = NULL;
+ }
+
  }
 
  return results;

wallet/wallet.h

@@ -165,6 +165,9 @@ struct forwarding {
  struct amount_msat msat_in, msat_out, fee;
  struct sha256_double *payment_hash;
  enum forward_status status;
+ struct timeabs received_time;
+ /* May not be present if the HTLC was not resolved yet. */
+ struct timeabs *resolved_time;
 };
 
 /* A database backed shachain struct. The datastructure is