Merge opentimestamps#33: Only calendar tx

2e0a21e init set with iterator, wordings (Riccardo Casatta)
ad5b6e0 use assert instead of sys.exit(1) (Riccardo Casatta)
e62198c correct some code comments (Riccardo Casatta)
c527e39 call serialize on tx instead of the named tuple (Riccardo Casatta)
4539b7f pep8 too long lines and function call typo (Riccardo Casatta)
ac02e66 rewrote do_bitcoin to consider only calendar's transactions (Riccardo Casatta)

Pull request description:

  After discussing we realize we first need a calendar version considering only his own tx, when this version is stabilized we are going to create a more complex version supporting external txs.
  First tests of this version on regtest looks working as desired, I am continuing testing but I let the reviewers to weigh in in the meantime.
  Some choice like exiting if there are no new blocks (line 279) aren't the most efficient approach but they are made to simplify the code and the reasoning.

Tree-SHA512: 566574a2c0b38df9716b5c7e54a09e12e4b6e6841d88961f0500e92e2257d3640fd20c8278282f1b164f0b641e51a38072a2e9ba9661195e9f74335a4eebd41d

Author: petertodd

otsserver/stamper.py

@@ -13,7 +13,7 @@
 import logging
 import threading
 import time
-
+import sys
 import bitcoin.rpc
 
 from bitcoin.core import COIN, b2lx, b2x, CTxIn, CTxOut, CTransaction, str_money_value
@@ -50,33 +50,19 @@ def make_btc_block_merkle_tree(blk_txids):
     return digests[0]
 
 
-def make_timestamp_from_block(digest, block, blockheight, serde_txs, *, max_tx_size=500):
-    """Make a timestamp for a message in a block with cached serialized txs
-    see python-opentimestamps.bitcoin.make_timestamp_from_block
-    """
-    len_smallest_tx_found = max_tx_size + 1
-    commitment_tx = None
-    prefix = None
-    suffix = None
-    for (tx, serialized_tx) in serde_txs:
-
-        if len(serialized_tx) > len_smallest_tx_found:
-            continue
-
-        try:
-            i = serialized_tx.index(digest)
-        except ValueError:
-            continue
+def make_timestamp_from_block_tx(confirmed_tx, block, blockheight):
 
-        # Found it!
-        commitment_tx = tx
-        prefix = serialized_tx[0:i]
-        suffix = serialized_tx[i + len(digest):]
+    commitment_tx = confirmed_tx.tx
+    serialized_tx = commitment_tx.serialize(params={'include_witness': False})
+    digest = confirmed_tx.tip_timestamp.msg
 
-        len_smallest_tx_found = len(serialized_tx)
+    try:
+        i = serialized_tx.index(digest)
+    except ValueError:
+        assert False, "can't build a block_timestamp from my tx, this is not supposed to happen, exiting"
 
-    if len_smallest_tx_found > max_tx_size:
-        return None, None
+    prefix = serialized_tx[0:i]
+    suffix = serialized_tx[i + len(digest):]
 
     digest_timestamp = Timestamp(digest)
 
@@ -102,7 +88,7 @@ def make_timestamp_from_block(digest, block, blockheight, serde_txs, *, max_tx_s
     attestation = BitcoinBlockHeaderAttestation(blockheight)
     merkleroot_stamp.attestations.add(attestation)
 
-    return digest_timestamp, CTransaction.deserialize(serialized_tx)
+    return digest_timestamp
 
 
 class OrderedSet(collections.OrderedDict):
@@ -130,7 +116,8 @@ def __detect_reorgs(self, proxy):
                 # rollback!
                 pass
 
-            logging.info("Reorg detected at height %d, rolling back block %s" % (self.__blocks[-1].height, b2lx(self.__blocks[-1].hash)))
+            logging.info("Reorg detected at height %d, rolling back block %s"
+                         % (self.__blocks[-1].height, b2lx(self.__blocks[-1].hash)))
             self.__blocks.pop(-1)
 
     def update_from_proxy(self, proxy):
@@ -210,15 +197,17 @@ def sort_filter_unspent(unspent):
                 except IndexError:
                     continue
 
-                confirmed_unspent.append({'outpoint':txin.prevout,
-                                          'amount':confirmed_outpoint['txout'].nValue})
+                confirmed_unspent.append({'outpoint': txin.prevout,
+                                          'amount': confirmed_outpoint['txout'].nValue})
 
         return sorted(confirmed_unspent, key=lambda x: x['amount'])
 
+
 class Stamper:
     """Timestamping bot"""
 
-    def __create_new_timestamp_tx_template(self, outpoint, txout_value, change_scriptPubKey):
+    @staticmethod
+    def __create_new_timestamp_tx_template(outpoint, txout_value, change_scriptPubKey):
         """Create a new timestamp transaction template
 
         The transaction created will have one input and two outputs, with the
@@ -232,7 +221,8 @@ def __create_new_timestamp_tx_template(self, outpoint, txout_value, change_scrip
                             [CTxOut(txout_value, change_scriptPubKey),
                              CTxOut(-1, CScript())])
 
-    def __update_timestamp_tx(self, old_tx, new_commitment, new_min_block_height, relay_feerate):
+    @staticmethod
+    def __update_timestamp_tx(old_tx, new_commitment, new_min_block_height, relay_feerate):
         """Update an existing timestamp transaction
 
         Returns the old transaction with a new commitment, and with the fee
@@ -271,20 +261,23 @@ def __pending_to_merkle_tree(self, n):
             tip_timestamp = make_merkle_tree(commitment_digest_timestamps)
             logging.debug("Done making merkle tree")
 
-            return (tip_timestamp, commitment_timestamps)
+            return tip_timestamp, commitment_timestamps
 
     def __do_bitcoin(self):
         """Do Bitcoin-related maintenance"""
 
-
-
         # FIXME: we shouldn't have to create a new proxy each time, but with
         # current python-bitcoinlib and the RPC implementation it seems that
         # the proxy connection can timeout w/o recovering properly.
         proxy = bitcoin.rpc.Proxy()
 
         new_blocks = self.known_blocks.update_from_proxy(proxy)
 
+        # code after this if it's executed only when we have new blocks, it simplify reasoning at the cost of not
+        # having a broadcasted tx immediately after we have a new cycle (the calendar wait the next block)
+        if not new_blocks:
+            return
+
         for (block_height, block_hash) in new_blocks:
             logging.info("New block %s at height %d" % (b2lx(block_hash), block_height))
 
@@ -301,7 +294,8 @@ def __do_bitcoin(self):
                 # FIXME: the reorged transaction might get mined in another
                 # block, so just adding the commitments for it back to the pool
                 # isn't ideal, but it is safe
-                logging.info('tx %s at height %d removed by reorg, adding %d commitments back to pending' % (b2lx(reorged_tx.tx.GetTxid()), block_height, len(reorged_tx.commitment_timestamps)))
+                logging.info('tx %s at height %d removed by reorg, adding %d commitments back to pending'
+                             % (b2lx(reorged_tx.tx.GetTxid()), block_height, len(reorged_tx.commitment_timestamps)))
                 for reorged_commitment_timestamp in reorged_tx.commitment_timestamps:
                     self.pending_commitments.add(reorged_commitment_timestamp.msg)
 
@@ -314,26 +308,25 @@ def __do_bitcoin(self):
                 logging.error("Failed to get block")
                 return
 
-            # the following is an optimization, by pre computing the serialization of tx
-            # we avoid this step for every unconfirmed tx
-            serde_txs = []
-            for tx in block.vtx:
-                serde_txs.append((tx, tx.serialize(params={'include_witness':False})))
+            # the following is an optimization, by pre computing the tx_id we rapidly check if our unconfirmed tx
+            # is in the block
+            block_txids = set(tx.GetTxid() for tx in block.vtx)
 
             # Check all potential pending txs against this block.
             # iterating in reverse order to prioritize most recent digest which commits to a bigger merkle tree
             for unconfirmed_tx in self.unconfirmed_txs[::-1]:
-                (block_timestamp, found_tx) = make_timestamp_from_block(unconfirmed_tx.tip_timestamp.msg, block,
-                                                                        block_height, serde_txs)
 
-                if block_timestamp is None:
+                if unconfirmed_tx.tx.GetTxid() not in block_txids:
                     continue
 
-                logging.info("Found %s which contains %s" % (b2lx(found_tx.GetTxid()),
-                                                             b2x(unconfirmed_tx.tip_timestamp.msg)))
+                confirmed_tx = unconfirmed_tx  # Success! Found tx
+                block_timestamp = make_timestamp_from_block_tx(confirmed_tx, block, block_height)
+
+                logging.info("Found commitment %s in tx %s"
+                             % (b2x(confirmed_tx.tip_timestamp.msg), b2lx(confirmed_tx.tx.GetTxid())))
                 # Success!
-                (tip_timestamp, commitment_timestamps) = self.__pending_to_merkle_tree(unconfirmed_tx.n)
-                mined_tx = TimestampTx(found_tx, tip_timestamp, commitment_timestamps)
+                (tip_timestamp, commitment_timestamps) = self.__pending_to_merkle_tree(confirmed_tx.n)
+                mined_tx = TimestampTx(confirmed_tx.tx, tip_timestamp, commitment_timestamps)
                 assert tip_timestamp.msg == unconfirmed_tx.tip_timestamp.msg
 
                 mined_tx.tip_timestamp.merge(block_timestamp)
@@ -350,26 +343,28 @@ def __do_bitcoin(self):
                 # have been mined, and are waiting for confirmations.
                 self.txs_waiting_for_confirmation[block_height] = mined_tx
 
-                # Erasing all unconfirmed txs if the transaction was mine
-                if mined_tx.tx.GetTxid() in self.mines:
-                    self.unconfirmed_txs.clear()
-                    self.mines.clear()
+                # Erase all unconfirmed txs, as they all conflict with each other
+                self.unconfirmed_txs.clear()
 
                 # And finally, we can reset the last time a timestamp
                 # transaction was mined to right now.
                 self.last_timestamp_tx = time.time()
 
                 break
 
-
         time_to_next_tx = int(self.last_timestamp_tx + self.min_tx_interval - time.time())
         if time_to_next_tx > 0:
             # Minimum interval between transactions hasn't been reached, so do nothing
             logging.debug("Waiting %ds before next tx" % time_to_next_tx)
             return
 
-        prev_tx = None
-        if self.pending_commitments and not self.unconfirmed_txs:
+        if not self.pending_commitments:
+            logging.debug("No pending commitments, no tx needed")
+            return
+
+        if self.unconfirmed_txs:
+            (prev_tx, prev_tip_timestamp, prev_commitment_timestamps) = self.unconfirmed_txs[-1]
+        else:  # first tx of a new cycle
             # Find the biggest unspent output that's confirmed
             unspent = find_unspent(proxy)
 
@@ -381,62 +376,59 @@ def __do_bitcoin(self):
             prev_tx = self.__create_new_timestamp_tx_template(unspent[-1]['outpoint'], unspent[-1]['amount'],
                                                               change_addr.to_scriptPubKey())
 
-            logging.debug('New timestamp tx, spending output %r, value %s' % (unspent[-1]['outpoint'], str_money_value(unspent[-1]['amount'])))
+            logging.debug('New timestamp tx, spending output %r, value %s' % (unspent[-1]['outpoint'],
+                                                                              str_money_value(unspent[-1]['amount'])))
 
-        elif self.unconfirmed_txs:
-            (prev_tx, prev_tip_timestamp, prev_commitment_timestamps) = self.unconfirmed_txs[-1]
+        (tip_timestamp, commitment_timestamps) = self.__pending_to_merkle_tree(len(self.pending_commitments))
+        logging.debug("New tip is %s" % b2x(tip_timestamp.msg))
+        # make_merkle_tree() seems to take long enough on really big adds
+        # that the proxy dies
+        proxy = bitcoin.rpc.Proxy()
 
-        # Send the first transaction even if we don't have a new block
-        if prev_tx and (new_blocks or not self.unconfirmed_txs):
-            (tip_timestamp, commitment_timestamps) = self.__pending_to_merkle_tree(len(self.pending_commitments))
-            logging.debug("New tip is %s" % b2x(tip_timestamp.msg))
-            # make_merkle_tree() seems to take long enough on really big adds
-            # that the proxy dies
-            proxy = bitcoin.rpc.Proxy()
-
-            sent_tx = None
-            relay_feerate = self.relay_feerate
-            while sent_tx is None:
-                unsigned_tx = self.__update_timestamp_tx(prev_tx, tip_timestamp.msg,
-                                                         proxy.getblockcount(), relay_feerate)
-
-                fee = _get_tx_fee(unsigned_tx, proxy)
-                if fee is None:
-                    logging.debug("Can't determine txfee of transaction; skipping")
-                    return
-                if fee > self.max_fee:
-                    logging.error("Maximum txfee reached!")
-                    return
-
-                r = proxy.signrawtransaction(unsigned_tx)
-                if not r['complete']:
-                    logging.error("Failed to sign transaction! r = %r" % r)
-                    return
-                signed_tx = r['tx']
+        sent_tx = None
+        relay_feerate = self.relay_feerate
+        while sent_tx is None:
+            unsigned_tx = self.__update_timestamp_tx(prev_tx, tip_timestamp.msg,
+                                                     proxy.getblockcount(), relay_feerate)
 
-                try:
-                    txid = proxy.sendrawtransaction(signed_tx)
-                except bitcoin.rpc.JSONRPCError as err:
-                    if err.error['code'] == -26:
-                        logging.debug("Err: %r" % err.error)
-                        # Insufficient priority - basically means we didn't
-                        # pay enough, so try again with a higher feerate
-                        relay_feerate *= 2
-                        continue
+            fee = _get_tx_fee(unsigned_tx, proxy)
+            if fee is None:
+                logging.debug("Can't determine txfee of transaction; skipping")
+                return
+            if fee > self.max_fee:
+                logging.error("Maximum txfee reached!")
+                return
 
-                    else:
-                        raise err  # something else, fail!
+            r = proxy.signrawtransaction(unsigned_tx)
+            if not r['complete']:
+                logging.error("Failed to sign transaction! r = %r" % r)
+                return
+            signed_tx = r['tx']
 
-                sent_tx = signed_tx
+            try:
+                proxy.sendrawtransaction(signed_tx)
+            except bitcoin.rpc.JSONRPCError as err:
+                if err.error['code'] == -26:
+                    logging.debug("Err: %r" % err.error)
+                    # Insufficient priority - basically means we didn't
+                    # pay enough, so try again with a higher feerate
+                    relay_feerate *= 2
+                    continue
 
-            if self.unconfirmed_txs:
-                logging.info("Sent timestamp tx %s, replacing %s; %d total commitments; %d prior tx versions" %
-                                (b2lx(sent_tx.GetTxid()), b2lx(prev_tx.GetTxid()), len(commitment_timestamps), len(self.unconfirmed_txs)))
-            else:
-                logging.info("Sent timestamp tx %s; %d total commitments" % (b2lx(sent_tx.GetTxid()), len(commitment_timestamps)))
+                else:
+                    raise err  # something else, fail!
 
-            self.unconfirmed_txs.append(UnconfirmedTimestampTx(sent_tx, tip_timestamp, len(commitment_timestamps)))
-            self.mines.add(sent_tx.GetTxid())
+            sent_tx = signed_tx
+
+        if self.unconfirmed_txs:
+            logging.info("Sent timestamp tx %s, replacing %s; %d total commitments; %d prior tx versions" %
+                         (b2lx(sent_tx.GetTxid()), b2lx(prev_tx.GetTxid()), len(commitment_timestamps),
+                          len(self.unconfirmed_txs)))
+        else:
+            logging.info("Sent timestamp tx %s; %d total commitments" % (b2lx(sent_tx.GetTxid()),
+                                                                         len(commitment_timestamps)))
+
+        self.unconfirmed_txs.append(UnconfirmedTimestampTx(sent_tx, tip_timestamp, len(commitment_timestamps)))
 
     def __loop(self):
         logging.info("Starting stamper loop")
@@ -460,7 +452,8 @@ def __loop(self):
                 # Is this commitment already stamped?
                 if commitment not in self.calendar:
                     self.pending_commitments.add(commitment)
-                    logging.debug('Added %s (idx %d) to pending commitments; %d total' % (b2x(commitment), idx, len(self.pending_commitments)))
+                    logging.debug('Added %s (idx %d) to pending commitments; %d total'
+                                  % (b2x(commitment), idx, len(self.pending_commitments)))
                 else:
                     if idx % 1000 == 0:
                         logging.debug('Commitment at idx %d already stamped' % idx)
@@ -496,7 +489,8 @@ def is_pending(self, commitment):
             for height, ttx in self.txs_waiting_for_confirmation.items():
                for commitment_timestamp in ttx.commitment_timestamps:
                     if commitment == commitment_timestamp.msg:
-                        return "Timestamped by transaction %s; waiting for %d confirmations" % (b2lx(ttx.tx.GetTxid()), self.min_confirmations-1)
+                        return "Timestamped by transaction %s; waiting for %d confirmations"\
+                               % (b2lx(ttx.tx.GetTxid()), self.min_confirmations-1)
 
             else:
                 return False
@@ -514,7 +508,7 @@ def __init__(self, calendar, exit_event, relay_feerate, min_confirmations, min_t
 
         self.known_blocks = KnownBlocks()
         self.unconfirmed_txs = []
-        self.mines = set()
+
         self.pending_commitments = OrderedSet()
         self.txs_waiting_for_confirmation = {}