Merge pull request #1918 from carver/key-logger

Add Database for tracking key accesses

Author: carver

Makefile

@@ -39,7 +39,6 @@ coverage:
 	open htmlcov/index.html
 
 build-docs:
-	pip install -e .[doc]
 	cd docs/; sphinx-build -W -T -E . _build/html
 
 doctest:

docs/guides/understanding_the_mining_process.rst

@@ -385,4 +385,4 @@ zero value transfer transaction.
   ... )
 
   >>> chain.mine_block(mix_hash=mix_hash, nonce=nonce)
-  <ByzantiumBlock(#Block #1)>
+  <ByzantiumBlock(#Block #1-0x41f6..2913)>

eth/abc.py

@@ -403,13 +403,24 @@ def delete(self, key: bytes) -> None:
         ...
 
 
+class AtomicWriteBatchAPI(DatabaseAPI):
+    """
+    The readable/writeable object returned by an atomic database when we start building
+    a batch of writes to commit.
+
+    Reads to this database will observe writes written during batching,
+    but the writes will not actually persist until this object is committed.
+    """
+    pass
+
+
 class AtomicDatabaseAPI(DatabaseAPI):
     """
     Like ``BatchDB``, but immediately write out changes if they are
     not in an ``atomic_batch()`` context.
     """
     @abstractmethod
-    def atomic_batch(self) -> ContextManager[DatabaseAPI]:
+    def atomic_batch(self) -> ContextManager[AtomicWriteBatchAPI]:
         """
         Return a :class:`~typing.ContextManager` to write an atomic batch to the database.
         """

eth/db/accesslog.py

@@ -0,0 +1,113 @@
+from contextlib import contextmanager
+import logging
+from typing import (
+    Iterator,
+    FrozenSet,
+    Set,
+)
+
+from eth.abc import (
+    AtomicWriteBatchAPI,
+    AtomicDatabaseAPI,
+    DatabaseAPI,
+)
+from eth.db.backends.base import (
+    BaseDB,
+)
+from eth.db.atomic import (
+    BaseAtomicDB,
+)
+
+
+class KeyAccessLoggerDB(BaseDB):
+    """
+    Wraps around a database, and tracks all the keys that were read since initialization.
+    """
+
+    logger = logging.getLogger("eth.db.KeyAccessLoggerDB")
+
+    def __init__(self, wrapped_db: DatabaseAPI, log_missing_keys: bool=True) -> None:
+        """
+        :param log_missing_keys: True if a key is added to :attr:`keys_read` even if the
+            key/value does not exist in the database.
+        """
+        self.wrapped_db = wrapped_db
+        self._keys_read: Set[bytes] = set()
+        self._log_missing_keys = log_missing_keys
+
+    @property
+    def keys_read(self) -> FrozenSet[bytes]:
+        # Make a defensive copy so callers can't modify the list externally
+        return frozenset(self._keys_read)
+
+    def __getitem__(self, key: bytes) -> bytes:
+        try:
+            result = self.wrapped_db.__getitem__(key)
+        except KeyError:
+            if self._log_missing_keys:
+                self._keys_read.add(key)
+            raise
+        else:
+            self._keys_read.add(key)
+            return result
+
+    def __setitem__(self, key: bytes, value: bytes) -> None:
+        self.wrapped_db[key] = value
+
+    def __delitem__(self, key: bytes) -> None:
+        del self.wrapped_db[key]
+
+    def _exists(self, key: bytes) -> bool:
+        does_exist = key in self.wrapped_db
+        if does_exist or self._log_missing_keys:
+            self._keys_read.add(key)
+        return does_exist
+
+
+class KeyAccessLoggerAtomicDB(BaseAtomicDB):
+    """
+    Wraps around an atomic database, and tracks all the keys that were read since initialization.
+    """
+    logger = logging.getLogger("eth.db.KeyAccessLoggerAtomicDB")
+
+    def __init__(self, wrapped_db: AtomicDatabaseAPI, log_missing_keys: bool=True) -> None:
+        """
+        :param log_missing_keys: True if a key is added to :attr:`keys_read` even if the
+            key/value does not exist in the database.
+        """
+        self.wrapped_db = wrapped_db
+        self._keys_read: Set[bytes] = set()
+        self._log_missing_keys = log_missing_keys
+
+    @property
+    def keys_read(self) -> FrozenSet[bytes]:
+        # Make a defensive copy so callers can't modify the list externally
+        return frozenset(self._keys_read)
+
+    def __getitem__(self, key: bytes) -> bytes:
+        try:
+            result = self.wrapped_db.__getitem__(key)
+        except KeyError:
+            if self._log_missing_keys:
+                self._keys_read.add(key)
+            raise
+        else:
+            self._keys_read.add(key)
+            return result
+
+    def __setitem__(self, key: bytes, value: bytes) -> None:
+        self.wrapped_db[key] = value
+
+    def __delitem__(self, key: bytes) -> None:
+        del self.wrapped_db[key]
+
+    def _exists(self, key: bytes) -> bool:
+        does_exist = key in self.wrapped_db
+        if does_exist or self._log_missing_keys:
+            self._keys_read.add(key)
+        return does_exist
+
+    @contextmanager
+    def atomic_batch(self) -> Iterator[AtomicWriteBatchAPI]:
+        with self.wrapped_db.atomic_batch() as readable_batch:
+            yield readable_batch

eth/db/atomic.py

@@ -9,6 +9,7 @@
 )
 
 from eth.abc import (
+    AtomicWriteBatchAPI,
     DatabaseAPI,
 )
 
@@ -17,7 +18,7 @@
     DBDiffTracker,
     DiffMissingError,
 )
-from eth.db.backends.base import BaseDB, BaseAtomicDB
+from eth.db.backends.base import BaseAtomicDB, BaseDB
 from eth.db.backends.memory import MemoryDB
 
 
@@ -46,12 +47,12 @@ def _exists(self, key: bytes) -> bool:
         return key in self.wrapped_db
 
     @contextmanager
-    def atomic_batch(self) -> Iterator['AtomicDBWriteBatch']:
+    def atomic_batch(self) -> Iterator[AtomicWriteBatchAPI]:
         with AtomicDBWriteBatch._commit_unless_raises(self) as readable_batch:
             yield readable_batch
 
 
-class AtomicDBWriteBatch(BaseDB):
+class AtomicDBWriteBatch(BaseDB, AtomicWriteBatchAPI):
     """
     This is returned by a BaseAtomicDB during an atomic_batch, to provide a temporary view
     of the database, before commit.
@@ -112,7 +113,7 @@ def _exists(self, key: bytes) -> bool:
 
     @classmethod
     @contextmanager
-    def _commit_unless_raises(cls, write_target_db: DatabaseAPI) -> Iterator['AtomicDBWriteBatch']:
+    def _commit_unless_raises(cls, write_target_db: DatabaseAPI) -> Iterator[AtomicWriteBatchAPI]:
         """
         Commit all writes inside the context, unless an exception was raised.
 

eth/db/backends/level.py

@@ -2,13 +2,16 @@
 import logging
 from pathlib import Path
 from typing import (
-    Generator,
+    Iterator,
     TYPE_CHECKING,
 )
 
 from eth_utils import ValidationError
 
-from eth.abc import DatabaseAPI
+from eth.abc import (
+    AtomicWriteBatchAPI,
+    DatabaseAPI,
+)
 from eth.db.diff import (
     DBDiffTracker,
     DiffMissingError,
@@ -67,7 +70,7 @@ def __delitem__(self, key: bytes) -> None:
         self.db.delete(key)
 
     @contextmanager
-    def atomic_batch(self) -> Generator['LevelDBWriteBatch', None, None]:
+    def atomic_batch(self) -> Iterator[AtomicWriteBatchAPI]:
         with self.db.write_batch(transaction=True) as atomic_batch:
             readable_batch = LevelDBWriteBatch(self, atomic_batch)
             try:
@@ -76,7 +79,7 @@ def atomic_batch(self) -> Generator['LevelDBWriteBatch', None, None]:
                 readable_batch.decommission()
 
 
-class LevelDBWriteBatch(BaseDB):
+class LevelDBWriteBatch(BaseDB, AtomicWriteBatchAPI):
     """
     A native leveldb write batch does not permit reads on the in-progress data.
     This class fills that gap, by tracking the in-progress diff, and adding

eth/rlp/blocks.py

@@ -2,10 +2,13 @@
     Type
 )
 
+from eth_utils import (
+    humanize_hash,
+)
+
 from eth._utils.datatypes import (
     Configurable,
 )
-
 from eth.abc import (
     BlockAPI,
     SignedTransactionAPI,
@@ -29,4 +32,5 @@ def __repr__(self) -> str:
         return f'<{self.__class__.__name__}(#{str(self)})>'
 
     def __str__(self) -> str:
-        return f"Block #{self.number}"
+        clipped_hash = humanize_hash(self.hash)
+        return f"Block #{self.number}-0x{clipped_hash}"

eth/tools/mining.py

@@ -1,19 +1,19 @@
+from eth.abc import (
+    BlockAPI,
+    VirtualMachineAPI,
+)
 from eth.consensus import (
     pow,
 )
 
-from eth.rlp.blocks import (
-    BaseBlock,
-)
-
 
-class POWMiningMixin:
+class POWMiningMixin(VirtualMachineAPI):
     """
     A VM that does POW mining as well. Should be used only in tests, when we
     need to programatically populate a ChainDB.
     """
-    def finalize_block(self, block: BaseBlock) -> BaseBlock:
-        block = super().finalize_block(block)  # type: ignore
+    def finalize_block(self, block: BlockAPI) -> BlockAPI:
+        block = super().finalize_block(block)
         nonce, mix_hash = pow.mine_pow_nonce(
             block.number, block.header.mining_hash, block.header.difficulty)
         return block.copy(header=block.header.copy(nonce=nonce, mix_hash=mix_hash))

newsfragments/1918.internal.rst

@@ -0,0 +1,3 @@
+Added :class:`~eth.db.accesslog.KeyAccessLoggerDB` and its atomic twin; faster ``make
+validate-docs`` (but you have to remember to ``pip install -e .[doc]`` yourself); ``str(block)`` now
+includes the first 3 bytes of the block hash.

tests/database/test_accesslog.py

@@ -0,0 +1,69 @@
+from hypothesis import (
+    given,
+    strategies as st,
+)
+import pytest
+
+from eth.db.accesslog import (
+    KeyAccessLoggerDB,
+    KeyAccessLoggerAtomicDB,
+)
+from eth.db.backends.memory import MemoryDB
+
+
+@given(st.lists(st.binary()))
+@pytest.mark.parametrize('DB', (
+    lambda: KeyAccessLoggerAtomicDB(MemoryDB()),
+    lambda: KeyAccessLoggerAtomicDB(MemoryDB(), log_missing_keys=False),
+    lambda: KeyAccessLoggerAtomicDB(MemoryDB(), log_missing_keys=True),
+    lambda: KeyAccessLoggerDB(MemoryDB()),
+    lambda: KeyAccessLoggerDB(MemoryDB(), log_missing_keys=False),
+    lambda: KeyAccessLoggerDB(MemoryDB(), log_missing_keys=True),
+))
+def test_log_accesses(DB, keys):
+    db = DB()
+    assert len(db.keys_read) == 0
+    for key in keys:
+        db[key] = b'placeholder'  # value doesn't matter
+        assert db[key] == b'placeholder'
+
+    for key in keys:
+        assert key in db.keys_read
+
+
+@pytest.mark.parametrize('DB', (
+    lambda: KeyAccessLoggerAtomicDB(MemoryDB()),
+    lambda: KeyAccessLoggerAtomicDB(MemoryDB(), log_missing_keys=True),
+    lambda: KeyAccessLoggerDB(MemoryDB()),
+    lambda: KeyAccessLoggerDB(MemoryDB(), log_missing_keys=True),
+))
+def test_logs_missing_keys(DB):
+    db_logs_missing = DB()
+    assert len(db_logs_missing.keys_read) == 0
+    assert b'exist-test' not in db_logs_missing
+
+    assert b'exist-test' in db_logs_missing.keys_read
+
+    with pytest.raises(KeyError, match='get-test'):
+        db_logs_missing[b'get-test']
+
+    assert b'get-test' in db_logs_missing.keys_read
+    assert len(db_logs_missing.keys_read) == 2
+
+
+@pytest.mark.parametrize('DB', (
+    lambda: KeyAccessLoggerAtomicDB(MemoryDB(), log_missing_keys=False),
+    lambda: KeyAccessLoggerDB(MemoryDB(), log_missing_keys=False),
+))
+def test_dont_log_missing_keys(DB):
+    db_doesnt_log_missing = DB()
+    assert len(db_doesnt_log_missing.keys_read) == 0
+    assert b'exist-test' not in db_doesnt_log_missing
+
+    assert b'exist-test' not in db_doesnt_log_missing.keys_read
+
+    with pytest.raises(KeyError, match='get-test'):
+        db_doesnt_log_missing[b'get-test']
+
+    assert b'get-test' not in db_doesnt_log_missing.keys_read
+    assert len(db_doesnt_log_missing.keys_read) == 0