diff --git a/setup.cfg b/setup.cfg index 51670eea1a8b93fa39c6191b37715f9b166e1c18..371a19b343c204fb576b2c6d8c77d969160d40e3 100644 --- a/setup.cfg +++ b/setup.cfg @@ -33,6 +33,7 @@ packages = install_requires = attrs zope.interface + eliot aniso8601 python-challenge-bypass-ristretto # Inherit our Twisted dependency from tahoe-lafs so we don't accidentally diff --git a/src/_zkapauthorizer/_plugin.py b/src/_zkapauthorizer/_plugin.py index 2ed966d8af44e357e789feb8bfc38bb2b92ef4c4..198a4cff84e31abadf283e3420ab9b4a1fa3d188 100644 --- a/src/_zkapauthorizer/_plugin.py +++ b/src/_zkapauthorizer/_plugin.py @@ -45,6 +45,11 @@ from twisted.internet.defer import ( succeed, ) +from eliot import ( + MessageType, + Field, +) + from allmydata.interfaces import ( IFoolscapStoragePlugin, IAnnounceableStorageServer, @@ -83,6 +88,24 @@ from .lease_maintenance import ( _log = Logger() +PRIVACYPASS_MESSAGE = Field( + u"message", + unicode, + u"The PrivacyPass request-binding data associated with a pass.", +) + +PASS_COUNT = Field( + u"count", + int, + u"A number of passes.", +) + +GET_PASSES = MessageType( + u"zkapauthorizer:get-passes", + [PRIVACYPASS_MESSAGE, PASS_COUNT], + u"Passes are being spent.", +) + @implementer(IAnnounceableStorageServer) @attr.s class AnnounceableStorageServer(object): @@ -167,7 +190,12 @@ class ZKAPAuthorizer(object): extract_unblinded_tokens = self._get_store(node_config).extract_unblinded_tokens def get_passes(message, count): unblinded_tokens = extract_unblinded_tokens(count) - return redeemer.tokens_to_passes(message, unblinded_tokens) + passes = redeemer.tokens_to_passes(message, unblinded_tokens) + GET_PASSES.log( + message=message, + count=count, + ) + return passes return ZKAPAuthorizerStorageClient( get_rref, diff --git a/src/_zkapauthorizer/tests/eliot.py b/src/_zkapauthorizer/tests/eliot.py new file mode 100644 index 0000000000000000000000000000000000000000..710737d948cc4e069d12c265277e95dee569e133 --- /dev/null +++ b/src/_zkapauthorizer/tests/eliot.py @@ -0,0 +1,90 @@ +# Copyright 2019 PrivateStorage.io, LLC +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +""" +Eliot testing helpers. +""" + +from __future__ import ( + absolute_import, +) + +from functools import ( + wraps, +) + +from unittest import ( + SkipTest, +) + +from eliot import ( + MemoryLogger, +) + +from eliot.testing import ( + swap_logger, + check_for_errors, +) + +# validate_logging and capture_logging copied from Eliot around 1.11. We +# can't upgrade past 1.7 because we're not Python 3 compatible. +def validate_logging(assertion, *assertionArgs, **assertionKwargs): + def decorator(function): + @wraps(function) + def wrapper(self, *args, **kwargs): + skipped = False + + kwargs["logger"] = logger = MemoryLogger() + self.addCleanup(check_for_errors, logger) + # TestCase runs cleanups in reverse order, and we want this to + # run *before* tracebacks are checked: + if assertion is not None: + self.addCleanup( + lambda: skipped + or assertion(self, logger, *assertionArgs, **assertionKwargs) + ) + try: + return function(self, *args, **kwargs) + except SkipTest: + skipped = True + raise + + return wrapper + + return decorator + + +def capture_logging(assertion, *assertionArgs, **assertionKwargs): + """ + Capture and validate all logging that doesn't specify a L{Logger}. + + See L{validate_logging} for details on the rest of its behavior. + """ + + def decorator(function): + @validate_logging(assertion, *assertionArgs, **assertionKwargs) + @wraps(function) + def wrapper(self, *args, **kwargs): + logger = kwargs["logger"] + previous_logger = swap_logger(logger) + + def cleanup(): + swap_logger(previous_logger) + + self.addCleanup(cleanup) + return function(self, *args, **kwargs) + + return wrapper + + return decorator diff --git a/src/_zkapauthorizer/tests/test_plugin.py b/src/_zkapauthorizer/tests/test_plugin.py index 48f8cfcee9ceed36b72dc9df7dd42953c1eee11f..aebfef6c913fbdee942b820245b75e22a1cf9175 100644 --- a/src/_zkapauthorizer/tests/test_plugin.py +++ b/src/_zkapauthorizer/tests/test_plugin.py @@ -41,7 +41,12 @@ from testtools import ( from testtools.matchers import ( Always, Contains, + Equals, AfterPreprocessing, + MatchesAll, + HasLength, + AllMatch, + ContainsDict, ) from testtools.twistedsupport import ( succeeded, @@ -79,6 +84,10 @@ from allmydata.client import ( create_client_from_config, ) +from eliot.testing import ( + LoggedMessage, +) + from twisted.python.filepath import ( FilePath, ) @@ -95,6 +104,10 @@ from twisted.plugins.zkapauthorizer import ( storage_server, ) +from .._plugin import ( + GET_PASSES, +) + from ..foolscap import ( RIPrivacyPassAuthorizedStorageServer, ) @@ -110,6 +123,7 @@ from ..controller import ( from ..storage_common import ( BYTES_PER_PASS, required_passes, + allocate_buckets_message, ) from .._storage_client import ( IncorrectStorageServerReference, @@ -143,6 +157,11 @@ from .foolscap import ( DummyReferenceable, ) +from .eliot import ( + capture_logging, +) + + SIGNING_KEY_PATH = FilePath(__file__).sibling(u"testing-signing.key") @@ -386,18 +405,20 @@ class ClientPluginTests(TestCase): ) @given( - tahoe_configs_with_dummy_redeemer, - datetimes(), - announcements(), - vouchers(), - storage_indexes(), - lease_renew_secrets(), - lease_cancel_secrets(), - sharenum_sets(), - sizes(), + get_config=tahoe_configs_with_dummy_redeemer, + now=datetimes(), + announcement=announcements(), + voucher=vouchers(), + storage_index=storage_indexes(), + renew_secret=lease_renew_secrets(), + cancel_secret=lease_cancel_secrets(), + sharenums=sharenum_sets(), + size=sizes(), ) + @capture_logging(lambda self, logger: logger.validate()) def test_unblinded_tokens_extracted( self, + logger, get_config, now, announcement, @@ -419,11 +440,12 @@ class ClientPluginTests(TestCase): ) store = VoucherStore.from_node_config(node_config, lambda: now) + expected_pass_cost = required_passes(BYTES_PER_PASS, [size] * len(sharenums)) controller = PaymentController( store, DummyRedeemer(), # Give it enough for the allocate_buckets call below. - required_passes(BYTES_PER_PASS, [size] * len(sharenums)), + expected_pass_cost, ) # Get a token inserted into the store. redeeming = controller.redeem(voucher) @@ -455,6 +477,23 @@ class ClientPluginTests(TestCase): raises(NotEnoughTokens), ) + messages = LoggedMessage.of_type(logger.messages, GET_PASSES) + self.assertThat( + messages, + MatchesAll( + HasLength(1), + AllMatch( + AfterPreprocessing( + lambda logged_message: logged_message.message, + ContainsDict({ + u"message": Equals(allocate_buckets_message(storage_index)), + u"count": Equals(expected_pass_cost), + }), + ), + ), + ), + ) + class ClientResourceTests(TestCase): """ diff --git a/zkapauthorizer.nix b/zkapauthorizer.nix index 5b113d7357028fd3e38017eaf6cf46eb60cee3df..a5e611b4c8879f65aa12c63c968de225a96834ac 100644 --- a/zkapauthorizer.nix +++ b/zkapauthorizer.nix @@ -1,6 +1,6 @@ { lib , buildPythonPackage, sphinx, git -, attrs, zope_interface, aniso8601, twisted, tahoe-lafs, challenge-bypass-ristretto, treq +, attrs, zope_interface, eliot, aniso8601, twisted, tahoe-lafs, challenge-bypass-ristretto, treq , fixtures, testtools, hypothesis, pyflakes, coverage , hypothesisProfile ? null , collectCoverage ? false @@ -31,6 +31,7 @@ buildPythonPackage rec { attrs zope_interface aniso8601 + eliot twisted tahoe-lafs challenge-bypass-ristretto