launchpad-reviewers team mailing list archive
-
launchpad-reviewers team
-
Mailing list archive
-
Message #27200
[Merge] ~cjwatson/launchpad:ppa-wsgi-auth-logging into launchpad:master
Colin Watson has proposed merging ~cjwatson/launchpad:ppa-wsgi-auth-logging into launchpad:master.
Commit message:
Add more logging to PPA authorization
Requested reviews:
Launchpad code reviewers (launchpad-reviewers)
For more details, see:
https://code.launchpad.net/~cjwatson/launchpad/+git/launchpad/+merge/404012
--
Your team Launchpad code reviewers is requested to review the proposed merge of ~cjwatson/launchpad:ppa-wsgi-auth-logging into launchpad:master.
diff --git a/lib/lp/soyuz/wsgi/archiveauth.py b/lib/lp/soyuz/wsgi/archiveauth.py
index 94f9f59..6da96e0 100644
--- a/lib/lp/soyuz/wsgi/archiveauth.py
+++ b/lib/lp/soyuz/wsgi/archiveauth.py
@@ -16,6 +16,7 @@ __all__ = [
import crypt
from random import SystemRandom
import string
+import sys
import time
import six
@@ -28,6 +29,17 @@ from lp.services.config import config
from lp.services.memcache.client import memcache_client_factory
+def _log(environ, message, *args):
+ """Log a message to the WSGI error stream."""
+ # Ideally we might set up a proper logger instead, but that's more
+ # effort than is justified by something this small.
+ error_stream = environ.get("wsgi.errors", sys.stderr)
+ if args:
+ message = message % args
+ error_stream.write(message + "\n")
+ error_stream.flush()
+
+
def _get_archive_reference(environ):
# Reconstruct the relevant part of the URL. We don't care about where
# we're installed.
@@ -39,6 +51,8 @@ def _get_archive_reference(environ):
path_parts = path.lstrip("/").split("/")
if len(path_parts) >= 3:
return "~%s/%s/%s" % (path_parts[0], path_parts[2], path_parts[1])
+ else:
+ _log(environ, "No archive reference found in URL '%s'.", path)
_sr = SystemRandom()
@@ -74,6 +88,7 @@ def check_password(environ, user, password):
crypted_password = _memcache_client.get(memcache_key)
if (crypted_password and
crypt.crypt(password, crypted_password) == crypted_password):
+ _log(environ, "%s@%s: Authorized (cached).", user, archive_reference)
return True
proxy = ServerProxy(config.personalpackagearchive.archive_api_endpoint)
try:
@@ -81,10 +96,15 @@ def check_password(environ, user, password):
# Cache positive responses for a minute to reduce database load.
_memcache_client.set(
memcache_key, _crypt_sha256(password), time.time() + 60)
+ _log(environ, "%s@%s: Authorized.", user, archive_reference)
return True
except Fault as e:
if e.faultCode == 410: # Unauthorized
+ _log(
+ environ, "%s@%s: Password does not match.",
+ user, archive_reference)
return False
else:
# Interpret any other fault as NotFound (320).
+ _log(environ, e.faultString)
return None
diff --git a/lib/lp/soyuz/wsgi/tests/test_archiveauth.py b/lib/lp/soyuz/wsgi/tests/test_archiveauth.py
index d33cb34..6749548 100644
--- a/lib/lp/soyuz/wsgi/tests/test_archiveauth.py
+++ b/lib/lp/soyuz/wsgi/tests/test_archiveauth.py
@@ -13,6 +13,7 @@ import subprocess
import time
from fixtures import MonkeyPatch
+import six
import transaction
from lp.services.config import config
@@ -39,32 +40,51 @@ class TestWSGIArchiveAuth(TestCaseWithFactory):
"lp.soyuz.wsgi.archiveauth._memcache_client",
self.memcache_fixture))
self.addCleanup(config.setInstance, config.instance_name)
+ self.resetLog()
+
+ def resetLog(self):
+ self.wsgi_errors = six.StringIO()
+
+ def assertLogs(self, message):
+ self.assertEqual(
+ [message] if message else [],
+ self.wsgi_errors.getvalue().splitlines())
def test_get_archive_reference_short_url(self):
self.assertIsNone(archiveauth._get_archive_reference(
- {"SCRIPT_NAME": "/foo"}))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": "/foo"}))
+ self.assertLogs("No archive reference found in URL '/foo'.")
def test_get_archive_reference_archive_base(self):
self.assertEqual(
"~user/ubuntu/ppa",
archiveauth._get_archive_reference(
- {"SCRIPT_NAME": "/user/ppa/ubuntu"}))
+ {"wsgi.errors": self.wsgi_errors,
+ "SCRIPT_NAME": "/user/ppa/ubuntu"}))
+ self.assertLogs("")
def test_get_archive_reference_inside_archive(self):
self.assertEqual(
"~user/ubuntu/ppa",
archiveauth._get_archive_reference(
- {"SCRIPT_NAME": "/user/ppa/ubuntu/dists"}))
+ {"wsgi.errors": self.wsgi_errors,
+ "SCRIPT_NAME": "/user/ppa/ubuntu/dists"}))
+ self.assertLogs("")
def test_check_password_short_url(self):
self.assertIsNone(archiveauth.check_password(
- {"SCRIPT_NAME": "/foo"}, "user", ""))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": "/foo"},
+ "user", ""))
self.assertEqual({}, self.memcache_fixture._cache)
+ self.assertLogs("No archive reference found in URL '/foo'.")
def test_check_password_not_found(self):
self.assertIsNone(archiveauth.check_password(
- {"SCRIPT_NAME": "/nonexistent/bad/unknown"}, "user", ""))
+ {"wsgi.errors": self.wsgi_errors,
+ "SCRIPT_NAME": "/nonexistent/bad/unknown"},
+ "user", ""))
self.assertEqual({}, self.memcache_fixture._cache)
+ self.assertLogs("No archive found for '~nonexistent/unknown/bad'.")
def test_crypt_sha256(self):
crypted_password = archiveauth._crypt_sha256("secret")
@@ -81,25 +101,33 @@ class TestWSGIArchiveAuth(TestCaseWithFactory):
return archive, archive_path, subscriber.name, token.token
def test_check_password_unauthorized(self):
- _, archive_path, username, password = self.makeArchiveAndToken()
+ archive, archive_path, username, password = self.makeArchiveAndToken()
# Test that this returns False, not merely something falsy (e.g.
# None).
self.assertIs(
False,
archiveauth.check_password(
- {"SCRIPT_NAME": archive_path}, username, password + "-bad"))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": archive_path},
+ username, password + "-bad"))
self.assertEqual({}, self.memcache_fixture._cache)
+ self.assertLogs(
+ "%s@~%s/ubuntu/%s: Password does not match." % (
+ username, archive.owner.name, archive.name))
def test_check_password_success(self):
archive, archive_path, username, password = self.makeArchiveAndToken()
self.assertIs(
True,
archiveauth.check_password(
- {"SCRIPT_NAME": archive_path}, username, password))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": archive_path},
+ username, password))
crypted_password = self.memcache_fixture.get(
"archive-auth:%s:%s" % (archive.reference, username))
self.assertEqual(
crypted_password, crypt.crypt(password, crypted_password))
+ self.assertLogs(
+ "%s@~%s/ubuntu/%s: Authorized." % (
+ username, archive.owner.name, archive.name))
def test_check_password_considers_cache(self):
class FakeProxy:
@@ -110,28 +138,51 @@ class TestWSGIArchiveAuth(TestCaseWithFactory):
password):
raise faults.Unauthorized()
- _, archive_path, username, password = self.makeArchiveAndToken()
+ archive, archive_path, username, password = self.makeArchiveAndToken()
self.assertIs(
True,
archiveauth.check_password(
- {"SCRIPT_NAME": archive_path}, username, password))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": archive_path},
+ username, password))
+ self.assertLogs(
+ "%s@~%s/ubuntu/%s: Authorized." % (
+ username, archive.owner.name, archive.name))
+ self.resetLog()
+
self.useFixture(
MonkeyPatch("lp.soyuz.wsgi.archiveauth.ServerProxy", FakeProxy))
+
# A subsequent check honours the cache.
self.assertIs(
False,
archiveauth.check_password(
- {"SCRIPT_NAME": archive_path}, username, password + "-bad"))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": archive_path},
+ username, password + "-bad"))
+ self.assertLogs(
+ "%s@~%s/ubuntu/%s: Password does not match." % (
+ username, archive.owner.name, archive.name))
+ self.resetLog()
+
self.assertIs(
True,
archiveauth.check_password(
- {"SCRIPT_NAME": archive_path}, username, password))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": archive_path},
+ username, password))
+ self.assertLogs(
+ "%s@~%s/ubuntu/%s: Authorized (cached)." % (
+ username, archive.owner.name, archive.name))
+ self.resetLog()
+
# If we advance time far enough, then the cached result expires.
self.now += 60
self.assertIs(
False,
archiveauth.check_password(
- {"SCRIPT_NAME": archive_path}, username, password))
+ {"wsgi.errors": self.wsgi_errors, "SCRIPT_NAME": archive_path},
+ username, password))
+ self.assertLogs(
+ "%s@~%s/ubuntu/%s: Password does not match." % (
+ username, archive.owner.name, archive.name))
def test_check_password_sets_config_instance(self):
test_instance_name = self.factory.getUniqueUnicode()
@@ -142,10 +193,14 @@ class TestWSGIArchiveAuth(TestCaseWithFactory):
self.assertIs(
True,
archiveauth.check_password(
- {"mod_wsgi.application_group": test_instance_name,
+ {"wsgi.errors": self.wsgi_errors,
+ "mod_wsgi.application_group": test_instance_name,
"SCRIPT_NAME": archive_path},
username, password))
self.assertEqual(test_instance_name, config.instance_name)
+ self.assertLogs(
+ "%s@~%s/ubuntu/%s: Authorized." % (
+ username, archive.owner.name, archive.name))
def test_script(self):
_, archive_path, username, password = self.makeArchiveAndToken()
diff --git a/lib/lp/soyuz/xmlrpc/archive.py b/lib/lp/soyuz/xmlrpc/archive.py
index 8507873..63cda23 100644
--- a/lib/lp/soyuz/xmlrpc/archive.py
+++ b/lib/lp/soyuz/xmlrpc/archive.py
@@ -10,6 +10,8 @@ __all__ = [
'ArchiveAPI',
]
+import logging
+
from pymacaroons import Macaroon
from zope.component import (
ComponentLookupError,
@@ -30,6 +32,9 @@ from lp.xmlrpc import faults
from lp.xmlrpc.helpers import return_fault
+log = logging.getLogger(__name__)
+
+
BUILDD_USER_NAME = "buildd"
@@ -59,6 +64,7 @@ class ArchiveAPI(LaunchpadXMLRPCView):
def _checkArchiveAuthToken(self, archive_reference, username, password):
archive = getUtility(IArchiveSet).getByReference(archive_reference)
if archive is None:
+ log.info("%s@%s: No archive found", username, archive_reference)
raise faults.NotFound(
message="No archive found for '%s'." % archive_reference)
archive = removeSecurityProxy(archive)
@@ -69,8 +75,12 @@ class ArchiveAPI(LaunchpadXMLRPCView):
if username == BUILDD_USER_NAME:
if self._verifyMacaroon(archive, password):
# Success.
+ log.info("%s@%s: Authorized", username, archive_reference)
return
else:
+ log.info(
+ "%s@%s: Macaroon verification failed",
+ username, archive_reference)
raise faults.Unauthorized()
# Fall back to checking archive auth tokens.
@@ -81,12 +91,17 @@ class ArchiveAPI(LaunchpadXMLRPCView):
token = token_set.getActiveTokenForArchiveAndPersonName(
archive, username)
if token is None:
+ log.info("%s@%s: No valid tokens", username, archive_reference)
raise faults.NotFound(
message="No valid tokens for '%s' in '%s'." % (
username, archive_reference))
secret = removeSecurityProxy(token).token
if password != secret:
+ log.info(
+ "%s@%s: Password does not match", username, archive_reference)
raise faults.Unauthorized()
+ else:
+ log.info("%s@%s: Authorized", username, archive_reference)
def checkArchiveAuthToken(self, archive_reference, username, password):
"""See `IArchiveAPI`."""
diff --git a/lib/lp/soyuz/xmlrpc/tests/test_archive.py b/lib/lp/soyuz/xmlrpc/tests/test_archive.py
index 86c6ffa..028a97b 100644
--- a/lib/lp/soyuz/xmlrpc/tests/test_archive.py
+++ b/lib/lp/soyuz/xmlrpc/tests/test_archive.py
@@ -7,6 +7,7 @@ from __future__ import absolute_import, print_function, unicode_literals
__metaclass__ = type
+from fixtures import FakeLogger
from zope.component import getUtility
from zope.security.proxy import removeSecurityProxy
@@ -30,35 +31,46 @@ class TestArchiveAPI(TestCaseWithFactory):
self.archive_api = ArchiveAPI(None, None)
self.pushConfig(
"launchpad", internal_macaroon_secret_key="some-secret")
+ self.logger = self.useFixture(FakeLogger())
- def assertNotFound(self, archive_reference, username, password, message):
+ def assertLogs(self, message):
+ self.assertEqual([message], self.logger.output.splitlines())
+
+ def assertNotFound(self, archive_reference, username, password, message,
+ log_message):
"""Assert that an archive auth token check returns NotFound."""
fault = self.archive_api.checkArchiveAuthToken(
archive_reference, username, password)
self.assertEqual(faults.NotFound(message), fault)
+ self.assertLogs(log_message)
- def assertUnauthorized(self, archive_reference, username, password):
+ def assertUnauthorized(self, archive_reference, username, password,
+ log_message):
"""Assert that an archive auth token check returns Unauthorized."""
fault = self.archive_api.checkArchiveAuthToken(
archive_reference, username, password)
self.assertEqual(faults.Unauthorized("Authorisation required."), fault)
+ self.assertLogs(log_message)
def test_checkArchiveAuthToken_unknown_archive(self):
self.assertNotFound(
"~nonexistent/unknown/bad", "user", "",
- "No archive found for '~nonexistent/unknown/bad'.")
+ "No archive found for '~nonexistent/unknown/bad'.",
+ "user@~nonexistent/unknown/bad: No archive found")
def test_checkArchiveAuthToken_no_tokens(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
self.assertNotFound(
archive.reference, "nobody", "",
- "No valid tokens for 'nobody' in '%s'." % archive.reference)
+ "No valid tokens for 'nobody' in '%s'." % archive.reference,
+ "nobody@%s: No valid tokens" % archive.reference)
def test_checkArchiveAuthToken_no_named_tokens(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
self.assertNotFound(
archive.reference, "+missing", "",
- "No valid tokens for '+missing' in '%s'." % archive.reference)
+ "No valid tokens for '+missing' in '%s'." % archive.reference,
+ "+missing@%s: No valid tokens" % archive.reference)
def test_checkArchiveAuthToken_buildd_macaroon_wrong_archive(self):
archive = self.factory.makeArchive(private=True)
@@ -70,7 +82,9 @@ class TestArchiveAPI(TestCaseWithFactory):
getUtility(IMacaroonIssuer, "binary-package-build"))
macaroon = issuer.issueMacaroon(build)
self.assertUnauthorized(
- other_archive.reference, "buildd", macaroon.serialize())
+ other_archive.reference, "buildd", macaroon.serialize(),
+ "buildd@%s: Macaroon verification failed" %
+ other_archive.reference)
def test_checkArchiveAuthToken_buildd_macaroon_not_building(self):
archive = self.factory.makeArchive(private=True)
@@ -79,7 +93,8 @@ class TestArchiveAPI(TestCaseWithFactory):
getUtility(IMacaroonIssuer, "binary-package-build"))
macaroon = issuer.issueMacaroon(build)
self.assertUnauthorized(
- archive.reference, "buildd", macaroon.serialize())
+ archive.reference, "buildd", macaroon.serialize(),
+ "buildd@%s: Macaroon verification failed" % archive.reference)
def test_checkArchiveAuthToken_buildd_macaroon_wrong_user(self):
archive = self.factory.makeArchive(private=True)
@@ -90,7 +105,8 @@ class TestArchiveAPI(TestCaseWithFactory):
macaroon = issuer.issueMacaroon(build)
self.assertNotFound(
archive.reference, "another-user", macaroon.serialize(),
- "No valid tokens for 'another-user' in '%s'." % archive.reference)
+ "No valid tokens for 'another-user' in '%s'." % archive.reference,
+ "another-user@%s: No valid tokens" % archive.reference)
def test_checkArchiveAuthToken_buildd_macaroon_correct(self):
archive = self.factory.makeArchive(private=True)
@@ -101,26 +117,30 @@ class TestArchiveAPI(TestCaseWithFactory):
macaroon = issuer.issueMacaroon(build)
self.assertIsNone(self.archive_api.checkArchiveAuthToken(
archive.reference, "buildd", macaroon.serialize()))
+ self.assertLogs("buildd@%s: Authorized" % archive.reference)
def test_checkArchiveAuthToken_named_token_wrong_password(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
token = archive.newNamedAuthToken("special")
- removeSecurityProxy(token).deactivate()
- self.assertNotFound(
- archive.reference, "+special", token.token,
- "No valid tokens for '+special' in '%s'." % archive.reference)
+ self.assertUnauthorized(
+ archive.reference, "+special", token.token + "-bad",
+ "+special@%s: Password does not match" % archive.reference)
def test_checkArchiveAuthToken_named_token_deactivated(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
token = archive.newNamedAuthToken("special")
- self.assertIsNone(self.archive_api.checkArchiveAuthToken(
- archive.reference, "+special", token.token))
+ removeSecurityProxy(token).deactivate()
+ self.assertNotFound(
+ archive.reference, "+special", token.token,
+ "No valid tokens for '+special' in '%s'." % archive.reference,
+ "+special@%s: No valid tokens" % archive.reference)
def test_checkArchiveAuthToken_named_token_correct_password(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
token = archive.newNamedAuthToken("special")
self.assertIsNone(self.archive_api.checkArchiveAuthToken(
archive.reference, "+special", token.token))
+ self.assertLogs("+special@%s: Authorized" % archive.reference)
def test_checkArchiveAuthToken_personal_token_wrong_password(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
@@ -128,7 +148,9 @@ class TestArchiveAPI(TestCaseWithFactory):
archive.newSubscription(subscriber, archive.owner)
token = archive.newAuthToken(subscriber)
self.assertUnauthorized(
- archive.reference, subscriber.name, token.token + "-bad")
+ archive.reference, subscriber.name, token.token + "-bad",
+ "%s@%s: Password does not match" % (
+ subscriber.name, archive.reference))
def test_checkArchiveAuthToken_personal_token_deactivated(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
@@ -139,7 +161,8 @@ class TestArchiveAPI(TestCaseWithFactory):
self.assertNotFound(
archive.reference, subscriber.name, token.token,
"No valid tokens for '%s' in '%s'." % (
- subscriber.name, archive.reference))
+ subscriber.name, archive.reference),
+ "%s@%s: No valid tokens" % (subscriber.name, archive.reference))
def test_checkArchiveAuthToken_personal_token_cancelled(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
@@ -150,7 +173,8 @@ class TestArchiveAPI(TestCaseWithFactory):
self.assertNotFound(
archive.reference, subscriber.name, token.token,
"No valid tokens for '%s' in '%s'." % (
- subscriber.name, archive.reference))
+ subscriber.name, archive.reference),
+ "%s@%s: No valid tokens" % (subscriber.name, archive.reference))
def test_checkArchiveAuthToken_personal_token_correct_password(self):
archive = removeSecurityProxy(self.factory.makeArchive(private=True))
@@ -159,3 +183,5 @@ class TestArchiveAPI(TestCaseWithFactory):
token = archive.newAuthToken(subscriber)
self.assertIsNone(self.archive_api.checkArchiveAuthToken(
archive.reference, subscriber.name, token.token))
+ self.assertLogs(
+ "%s@%s: Authorized" % (subscriber.name, archive.reference))
diff --git a/scripts/wsgi-archive-auth.py b/scripts/wsgi-archive-auth.py
index 3640ed1..f447b6a 100755
--- a/scripts/wsgi-archive-auth.py
+++ b/scripts/wsgi-archive-auth.py
@@ -55,10 +55,8 @@ def main():
result = check_password(
{"SCRIPT_NAME": args.archive_path}, args.username, args.password)
if result is None:
- print("Archive or user does not exist.", file=sys.stderr)
return 2
elif result is False:
- print("Password does not match.", file=sys.stderr)
return 1
elif result is True:
return 0
