Merge pull request #2722 from mempool/mononaut/ln-penalty-scan-optimization

Optimize force close penalty scans

backend/mempool-config.sample.json

@@ -82,7 +82,8 @@
     "BACKEND": "lnd",
     "STATS_REFRESH_INTERVAL": 600,
     "GRAPH_REFRESH_INTERVAL": 600,
-    "LOGGER_UPDATE_INTERVAL": 30
+    "LOGGER_UPDATE_INTERVAL": 30,
+    "FORENSICS_INTERVAL": 43200
   },
   "LND": {
     "TLS_CERT_PATH": "tls.cert",

backend/src/__fixtures__/mempool-config.template.json

@@ -98,7 +98,8 @@
     "TOPOLOGY_FOLDER": "__LIGHTNING_TOPOLOGY_FOLDER__",
     "STATS_REFRESH_INTERVAL": 600,
     "GRAPH_REFRESH_INTERVAL": 600,
-    "LOGGER_UPDATE_INTERVAL": 30
+    "LOGGER_UPDATE_INTERVAL": 30,
+    "FORENSICS_INTERVAL": 43200
   },
   "LND": {
     "TLS_CERT_PATH": "",

backend/src/config.ts

@@ -41,6 +41,7 @@ interface IConfig {
     STATS_REFRESH_INTERVAL: number;
     GRAPH_REFRESH_INTERVAL: number;
     LOGGER_UPDATE_INTERVAL: number;
+    FORENSICS_INTERVAL: number;
   };
   LND: {
     TLS_CERT_PATH: string;
@@ -199,6 +200,7 @@ const defaults: IConfig = {
     'STATS_REFRESH_INTERVAL': 600,
     'GRAPH_REFRESH_INTERVAL': 600,
     'LOGGER_UPDATE_INTERVAL': 30,
+    'FORENSICS_INTERVAL': 43200,
   },
   'LND': {
     'TLS_CERT_PATH': '',

backend/src/index.ts

@@ -35,6 +35,7 @@ import bisqRoutes from './api/bisq/bisq.routes';
 import liquidRoutes from './api/liquid/liquid.routes';
 import bitcoinRoutes from './api/bitcoin/bitcoin.routes';
 import fundingTxFetcher from './tasks/lightning/sync-tasks/funding-tx-fetcher';
+import forensicsService from './tasks/lightning/forensics.service';
 
 class Server {
   private wss: WebSocket.Server | undefined;
@@ -192,6 +193,7 @@ class Server {
     try {
       await fundingTxFetcher.$init();
       await networkSyncService.$startService();
+      await forensicsService.$startService();
       await lightningStatsUpdater.$startService();
     } catch(e) {
       logger.err(`Nodejs lightning backend crashed. Restarting in 1 minute. Reason: ${(e instanceof Error ? e.message : e)}`);

backend/src/tasks/lightning/forensics.service.ts

@@ -0,0 +1,225 @@
+import DB from '../../database';
+import logger from '../../logger';
+import channelsApi from '../../api/explorer/channels.api';
+import bitcoinApi from '../../api/bitcoin/bitcoin-api-factory';
+import config from '../../config';
+import { IEsploraApi } from '../../api/bitcoin/esplora-api.interface';
+import { Common } from '../../api/common';
+
+const throttleDelay = 20; //ms
+
+class ForensicsService {
+  loggerTimer = 0;
+  closedChannelsScanBlock = 0;
+  txCache: { [txid: string]: IEsploraApi.Transaction } = {};
+
+  constructor() {}
+
+  public async $startService(): Promise<void> {
+    logger.info('Starting lightning network forensics service');
+
+    this.loggerTimer = new Date().getTime() / 1000;
+
+    await this.$runTasks();
+  }
+
+  private async $runTasks(): Promise<void> {
+    try {
+      logger.info(`Running forensics scans`);
+
+      if (config.MEMPOOL.BACKEND === 'esplora') {
+        await this.$runClosedChannelsForensics(false);
+      }
+
+    } catch (e) {
+      logger.err('ForensicsService.$runTasks() error: ' + (e instanceof Error ? e.message : e));
+    }
+
+    setTimeout(() => { this.$runTasks(); }, 1000 * config.LIGHTNING.FORENSICS_INTERVAL);
+  }
+
+  /*
+    1. Mutually closed
+    2. Forced closed
+    3. Forced closed with penalty
+
+    ┌────────────────────────────────────┐       ┌────────────────────────────┐
+    │ outputs contain revocation script? ├──yes──► force close w/ penalty = 3 │
+    └──────────────┬─────────────────────┘       └────────────────────────────┘
+                   no
+    ┌──────────────▼──────────────────────────┐
+    │ outputs contain other lightning script? ├──┐
+    └──────────────┬──────────────────────────┘  │
+                   no                           yes
+    ┌──────────────▼─────────────┐               │
+    │ sequence starts with 0x80  │      ┌────────▼────────┐
+    │           and              ├──────► force close = 2 │
+    │ locktime starts with 0x20? │      └─────────────────┘
+    └──────────────┬─────────────┘
+                   no
+         ┌─────────▼────────┐
+         │ mutual close = 1 │
+         └──────────────────┘
+  */
+
+  public async $runClosedChannelsForensics(onlyNewChannels: boolean = false): Promise<void> {
+    if (config.MEMPOOL.BACKEND !== 'esplora') {
+      return;
+    }
+
+    let progress = 0;
+
+    try {
+      logger.info(`Started running closed channel forensics...`);
+      let channels;
+      if (onlyNewChannels) {
+        channels = await channelsApi.$getClosedChannelsWithoutReason();
+      } else {
+        channels = await channelsApi.$getUnresolvedClosedChannels();
+      }
+
+      for (const channel of channels) {
+        let reason = 0;
+        let resolvedForceClose = false;
+        // Only Esplora backend can retrieve spent transaction outputs
+        const cached: string[] = [];
+        try {
+          let outspends: IEsploraApi.Outspend[] | undefined;
+          try {
+            outspends = await bitcoinApi.$getOutspends(channel.closing_transaction_id);
+            await Common.sleep$(throttleDelay);
+          } catch (e) {
+            logger.err(`Failed to call ${config.ESPLORA.REST_API_URL + '/tx/' + channel.closing_transaction_id + '/outspends'}. Reason ${e instanceof Error ? e.message : e}`);
+            continue;
+          }
+          const lightningScriptReasons: number[] = [];
+          for (const outspend of outspends) {
+            if (outspend.spent && outspend.txid) {
+              let spendingTx: IEsploraApi.Transaction | undefined = this.txCache[outspend.txid];
+              if (!spendingTx) {
+                try {
+                  spendingTx = await bitcoinApi.$getRawTransaction(outspend.txid);
+                  await Common.sleep$(throttleDelay);
+                  this.txCache[outspend.txid] = spendingTx;
+                } catch (e) {
+                  logger.err(`Failed to call ${config.ESPLORA.REST_API_URL + '/tx/' + outspend.txid}. Reason ${e instanceof Error ? e.message : e}`);
+                  continue;
+                }
+              }
+              cached.push(spendingTx.txid);
+              const lightningScript = this.findLightningScript(spendingTx.vin[outspend.vin || 0]);
+              lightningScriptReasons.push(lightningScript);
+            }
+          }
+          const filteredReasons = lightningScriptReasons.filter((r) => r !== 1);
+          if (filteredReasons.length) {
+            if (filteredReasons.some((r) => r === 2 || r === 4)) {
+              reason = 3;
+            } else {
+              reason = 2;
+              resolvedForceClose = true;
+            }
+          } else {
+            /*
+              We can detect a commitment transaction (force close) by reading Sequence and Locktime
+              https://github.com/lightning/bolts/blob/master/03-transactions.md#commitment-transaction
+            */
+            let closingTx: IEsploraApi.Transaction | undefined = this.txCache[channel.closing_transaction_id];
+            if (!closingTx) {
+              try {
+                closingTx = await bitcoinApi.$getRawTransaction(channel.closing_transaction_id);
+                await Common.sleep$(throttleDelay);
+                this.txCache[channel.closing_transaction_id] = closingTx;
+              } catch (e) {
+                logger.err(`Failed to call ${config.ESPLORA.REST_API_URL + '/tx/' + channel.closing_transaction_id}. Reason ${e instanceof Error ? e.message : e}`);
+                continue;
+              }
+            }
+            cached.push(closingTx.txid);
+            const sequenceHex: string = closingTx.vin[0].sequence.toString(16);
+            const locktimeHex: string = closingTx.locktime.toString(16);
+            if (sequenceHex.substring(0, 2) === '80' && locktimeHex.substring(0, 2) === '20') {
+              reason = 2; // Here we can't be sure if it's a penalty or not
+            } else {
+              reason = 1;
+            }
+          }
+          if (reason) {
+            logger.debug('Setting closing reason ' + reason + ' for channel: ' + channel.id + '.');
+            await DB.query(`UPDATE channels SET closing_reason = ? WHERE id = ?`, [reason, channel.id]);
+            if (reason === 2 && resolvedForceClose) {
+              await DB.query(`UPDATE channels SET closing_resolved = ? WHERE id = ?`, [true, channel.id]);
+            }
+            if (reason !== 2 || resolvedForceClose) {
+              cached.forEach(txid => {
+                delete this.txCache[txid];
+              });
+            }
+          }
+        } catch (e) {
+          logger.err(`$runClosedChannelsForensics() failed for channel ${channel.short_id}. Reason: ${e instanceof Error ? e.message : e}`);
+        }
+
+        ++progress;
+        const elapsedSeconds = Math.round((new Date().getTime() / 1000) - this.loggerTimer);
+        if (elapsedSeconds > 10) {
+          logger.info(`Updating channel closed channel forensics ${progress}/${channels.length}`);
+          this.loggerTimer = new Date().getTime() / 1000;
+        }
+      }
+      logger.info(`Closed channels forensics scan complete.`);
+    } catch (e) {
+      logger.err('$runClosedChannelsForensics() error: ' + (e instanceof Error ? e.message : e));
+    }
+  }
+
+  private findLightningScript(vin: IEsploraApi.Vin): number {
+    const topElement = vin.witness[vin.witness.length - 2];
+      if (/^OP_IF OP_PUSHBYTES_33 \w{66} OP_ELSE OP_PUSH(NUM_\d+|BYTES_(1 \w{2}|2 \w{4})) OP_CSV OP_DROP OP_PUSHBYTES_33 \w{66} OP_ENDIF OP_CHECKSIG$/.test(vin.inner_witnessscript_asm)) {
+        // https://github.com/lightning/bolts/blob/master/03-transactions.md#commitment-transaction-outputs
+        if (topElement === '01') {
+          // top element is '01' to get in the revocation path
+          // 'Revoked Lightning Force Close';
+          // Penalty force closed
+          return 2;
+        } else {
+          // top element is '', this is a delayed to_local output
+          // 'Lightning Force Close';
+          return 3;
+        }
+      } else if (
+        /^OP_DUP OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUAL OP_IF OP_CHECKSIG OP_ELSE OP_PUSHBYTES_33 \w{66} OP_SWAP OP_SIZE OP_PUSHBYTES_1 20 OP_EQUAL OP_NOTIF OP_DROP OP_PUSHNUM_2 OP_SWAP OP_PUSHBYTES_33 \w{66} OP_PUSHNUM_2 OP_CHECKMULTISIG OP_ELSE OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUALVERIFY OP_CHECKSIG OP_ENDIF (OP_PUSHNUM_1 OP_CSV OP_DROP |)OP_ENDIF$/.test(vin.inner_witnessscript_asm) ||
+        /^OP_DUP OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUAL OP_IF OP_CHECKSIG OP_ELSE OP_PUSHBYTES_33 \w{66} OP_SWAP OP_SIZE OP_PUSHBYTES_1 20 OP_EQUAL OP_IF OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUALVERIFY OP_PUSHNUM_2 OP_SWAP OP_PUSHBYTES_33 \w{66} OP_PUSHNUM_2 OP_CHECKMULTISIG OP_ELSE OP_DROP OP_PUSHBYTES_3 \w{6} OP_CLTV OP_DROP OP_CHECKSIG OP_ENDIF (OP_PUSHNUM_1 OP_CSV OP_DROP |)OP_ENDIF$/.test(vin.inner_witnessscript_asm)
+      ) {
+        // https://github.com/lightning/bolts/blob/master/03-transactions.md#offered-htlc-outputs
+        // https://github.com/lightning/bolts/blob/master/03-transactions.md#received-htlc-outputs
+        if (topElement.length === 66) {
+          // top element is a public key
+          // 'Revoked Lightning HTLC'; Penalty force closed
+          return 4;
+        } else if (topElement) {
+          // top element is a preimage
+          // 'Lightning HTLC';
+          return 5;
+        } else {
+          // top element is '' to get in the expiry of the script
+          // 'Expired Lightning HTLC';
+          return 6;
+        }
+      } else if (/^OP_PUSHBYTES_33 \w{66} OP_CHECKSIG OP_IFDUP OP_NOTIF OP_PUSHNUM_16 OP_CSV OP_ENDIF$/.test(vin.inner_witnessscript_asm)) {
+        // https://github.com/lightning/bolts/blob/master/03-transactions.md#to_local_anchor-and-to_remote_anchor-output-option_anchors
+        if (topElement) {
+          // top element is a signature
+          // 'Lightning Anchor';
+          return 7;
+        } else {
+          // top element is '', it has been swept after 16 blocks
+          // 'Swept Lightning Anchor';
+          return 8;
+        }
+      }
+      return 1;
+  }
+}
+
+export default new ForensicsService();

backend/src/tasks/lightning/network-sync.service.ts

@@ -14,6 +14,7 @@ import NodesSocketsRepository from '../../repositories/NodesSocketsRepository';
 import { Common } from '../../api/common';
 import blocks from '../../api/blocks';
 import NodeRecordsRepository from '../../repositories/NodeRecordsRepository';
+import forensicsService from './forensics.service';
 
 class NetworkSyncService {
   loggerTimer = 0;
@@ -46,8 +47,10 @@ class NetworkSyncService {
       await this.$lookUpCreationDateFromChain();
       await this.$updateNodeFirstSeen();
       await this.$scanForClosedChannels();
+      
       if (config.MEMPOOL.BACKEND === 'esplora') {
-        await this.$runClosedChannelsForensics();
+        // run forensics on new channels only
+        await forensicsService.$runClosedChannelsForensics(true);
       }
 
     } catch (e) {
@@ -301,174 +304,6 @@ class NetworkSyncService {
       logger.err('$scanForClosedChannels() error: ' + (e instanceof Error ? e.message : e));
     }
   }
-
-  /*
-    1. Mutually closed
-    2. Forced closed
-    3. Forced closed with penalty
-
-    ┌────────────────────────────────────┐       ┌────────────────────────────┐
-    │ outputs contain revocation script? ├──yes──► force close w/ penalty = 3 │
-    └──────────────┬─────────────────────┘       └────────────────────────────┘
-                   no
-    ┌──────────────▼──────────────────────────┐
-    │ outputs contain other lightning script? ├──┐
-    └──────────────┬──────────────────────────┘  │
-                   no                           yes
-    ┌──────────────▼─────────────┐               │
-    │ sequence starts with 0x80  │      ┌────────▼────────┐
-    │           and              ├──────► force close = 2 │
-    │ locktime starts with 0x20? │      └─────────────────┘
-    └──────────────┬─────────────┘
-                   no
-         ┌─────────▼────────┐
-         │ mutual close = 1 │
-         └──────────────────┘
-  */
-
-  private async $runClosedChannelsForensics(skipUnresolved: boolean = false): Promise<void> {
-    if (!config.ESPLORA.REST_API_URL) {
-      return;
-    }
-
-    let progress = 0;
-
-    try {
-      logger.info(`Started running closed channel forensics...`);
-      let channels;
-      const closedChannels = await channelsApi.$getClosedChannelsWithoutReason();
-      if (skipUnresolved) {
-        channels = closedChannels;
-      } else {
-        const unresolvedChannels = await channelsApi.$getUnresolvedClosedChannels();
-        channels = [...closedChannels, ...unresolvedChannels];
-      }
-
-      for (const channel of channels) {
-        let reason = 0;
-        let resolvedForceClose = false;
-        // Only Esplora backend can retrieve spent transaction outputs
-        try {
-          let outspends: IEsploraApi.Outspend[] | undefined;
-          try {
-            outspends = await bitcoinApi.$getOutspends(channel.closing_transaction_id);
-          } catch (e) {
-            logger.err(`Failed to call ${config.ESPLORA.REST_API_URL + '/tx/' + channel.closing_transaction_id + '/outspends'}. Reason ${e instanceof Error ? e.message : e}`);
-            continue;
-          }
-          const lightningScriptReasons: number[] = [];
-          for (const outspend of outspends) {
-            if (outspend.spent && outspend.txid) {
-              let spendingTx: IEsploraApi.Transaction | undefined;
-              try {
-                spendingTx = await bitcoinApi.$getRawTransaction(outspend.txid);
-              } catch (e) {
-                logger.err(`Failed to call ${config.ESPLORA.REST_API_URL + '/tx/' + outspend.txid}. Reason ${e instanceof Error ? e.message : e}`);
-                continue;
-              }
-              const lightningScript = this.findLightningScript(spendingTx.vin[outspend.vin || 0]);
-              lightningScriptReasons.push(lightningScript);
-            }
-          }
-          const filteredReasons = lightningScriptReasons.filter((r) => r !== 1);
-          if (filteredReasons.length) {
-            if (filteredReasons.some((r) => r === 2 || r === 4)) {
-              reason = 3;
-            } else {
-              reason = 2;
-              resolvedForceClose = true;
-            }
-          } else {
-            /*
-              We can detect a commitment transaction (force close) by reading Sequence and Locktime
-              https://github.com/lightning/bolts/blob/master/03-transactions.md#commitment-transaction
-            */
-            let closingTx: IEsploraApi.Transaction | undefined;
-            try {
-              closingTx = await bitcoinApi.$getRawTransaction(channel.closing_transaction_id);
-            } catch (e) {
-              logger.err(`Failed to call ${config.ESPLORA.REST_API_URL + '/tx/' + channel.closing_transaction_id}. Reason ${e instanceof Error ? e.message : e}`);
-              continue;
-            }
-            const sequenceHex: string = closingTx.vin[0].sequence.toString(16);
-            const locktimeHex: string = closingTx.locktime.toString(16);
-            if (sequenceHex.substring(0, 2) === '80' && locktimeHex.substring(0, 2) === '20') {
-              reason = 2; // Here we can't be sure if it's a penalty or not
-            } else {
-              reason = 1;
-            }
-          }
-          if (reason) {
-            logger.debug('Setting closing reason ' + reason + ' for channel: ' + channel.id + '.');
-            await DB.query(`UPDATE channels SET closing_reason = ? WHERE id = ?`, [reason, channel.id]);
-            if (reason === 2 && resolvedForceClose) {
-              await DB.query(`UPDATE channels SET closing_resolved = ? WHERE id = ?`, [true, channel.id]);
-            }
-          }
-        } catch (e) {
-          logger.err(`$runClosedChannelsForensics() failed for channel ${channel.short_id}. Reason: ${e instanceof Error ? e.message : e}`);
-        }
-
-        ++progress;
-        const elapsedSeconds = Math.round((new Date().getTime() / 1000) - this.loggerTimer);
-        if (elapsedSeconds > 10) {
-          logger.info(`Updating channel closed channel forensics ${progress}/${channels.length}`);
-          this.loggerTimer = new Date().getTime() / 1000;
-        }
-      }
-      logger.info(`Closed channels forensics scan complete.`);
-    } catch (e) {
-      logger.err('$runClosedChannelsForensics() error: ' + (e instanceof Error ? e.message : e));
-    }
-  }
-
-  private findLightningScript(vin: IEsploraApi.Vin): number {
-    const topElement = vin.witness[vin.witness.length - 2];
-      if (/^OP_IF OP_PUSHBYTES_33 \w{66} OP_ELSE OP_PUSH(NUM_\d+|BYTES_(1 \w{2}|2 \w{4})) OP_CSV OP_DROP OP_PUSHBYTES_33 \w{66} OP_ENDIF OP_CHECKSIG$/.test(vin.inner_witnessscript_asm)) {
-        // https://github.com/lightning/bolts/blob/master/03-transactions.md#commitment-transaction-outputs
-        if (topElement === '01') {
-          // top element is '01' to get in the revocation path
-          // 'Revoked Lightning Force Close';
-          // Penalty force closed
-          return 2;
-        } else {
-          // top element is '', this is a delayed to_local output
-          // 'Lightning Force Close';
-          return 3;
-        }
-      } else if (
-        /^OP_DUP OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUAL OP_IF OP_CHECKSIG OP_ELSE OP_PUSHBYTES_33 \w{66} OP_SWAP OP_SIZE OP_PUSHBYTES_1 20 OP_EQUAL OP_NOTIF OP_DROP OP_PUSHNUM_2 OP_SWAP OP_PUSHBYTES_33 \w{66} OP_PUSHNUM_2 OP_CHECKMULTISIG OP_ELSE OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUALVERIFY OP_CHECKSIG OP_ENDIF (OP_PUSHNUM_1 OP_CSV OP_DROP |)OP_ENDIF$/.test(vin.inner_witnessscript_asm) ||
-        /^OP_DUP OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUAL OP_IF OP_CHECKSIG OP_ELSE OP_PUSHBYTES_33 \w{66} OP_SWAP OP_SIZE OP_PUSHBYTES_1 20 OP_EQUAL OP_IF OP_HASH160 OP_PUSHBYTES_20 \w{40} OP_EQUALVERIFY OP_PUSHNUM_2 OP_SWAP OP_PUSHBYTES_33 \w{66} OP_PUSHNUM_2 OP_CHECKMULTISIG OP_ELSE OP_DROP OP_PUSHBYTES_3 \w{6} OP_CLTV OP_DROP OP_CHECKSIG OP_ENDIF (OP_PUSHNUM_1 OP_CSV OP_DROP |)OP_ENDIF$/.test(vin.inner_witnessscript_asm)
-      ) {
-        // https://github.com/lightning/bolts/blob/master/03-transactions.md#offered-htlc-outputs
-        // https://github.com/lightning/bolts/blob/master/03-transactions.md#received-htlc-outputs
-        if (topElement.length === 66) {
-          // top element is a public key
-          // 'Revoked Lightning HTLC'; Penalty force closed
-          return 4;
-        } else if (topElement) {
-          // top element is a preimage
-          // 'Lightning HTLC';
-          return 5;
-        } else {
-          // top element is '' to get in the expiry of the script
-          // 'Expired Lightning HTLC';
-          return 6;
-        }
-      } else if (/^OP_PUSHBYTES_33 \w{66} OP_CHECKSIG OP_IFDUP OP_NOTIF OP_PUSHNUM_16 OP_CSV OP_ENDIF$/.test(vin.inner_witnessscript_asm)) {
-        // https://github.com/lightning/bolts/blob/master/03-transactions.md#to_local_anchor-and-to_remote_anchor-output-option_anchors
-        if (topElement) {
-          // top element is a signature
-          // 'Lightning Anchor';
-          return 7;
-        } else {
-          // top element is '', it has been swept after 16 blocks
-          // 'Swept Lightning Anchor';
-          return 8;
-        }
-      }
-      return 1;
-  }
 }
 
 export default new NetworkSyncService();