launchpad-reviewers team mailing list archive
-
launchpad-reviewers team
-
Mailing list archive
-
Message #24073
[Merge] ~cjwatson/launchpad:git-xmlrpc-log-request-id into launchpad:master
Colin Watson has proposed merging ~cjwatson/launchpad:git-xmlrpc-log-request-id into launchpad:master.
Commit message:
Log requests and responses in Git XML-RPC endpoint
LP: #1846313
Requested reviews:
Launchpad code reviewers (launchpad-reviewers)
Related bugs:
Bug #1846313 in Launchpad itself: "Git XML-RPC requests should log response with request-id"
https://bugs.launchpad.net/launchpad/+bug/1846313
For more details, see:
https://code.launchpad.net/~cjwatson/launchpad/+git/launchpad/+merge/374221
I don't love the test changes here, but I've tried to make them as clean as possible.
--
Your team Launchpad code reviewers is requested to review the proposed merge of ~cjwatson/launchpad:git-xmlrpc-log-request-id into launchpad:master.
diff --git a/lib/lp/code/xmlrpc/git.py b/lib/lp/code/xmlrpc/git.py
index d85aae7..cbf9205 100644
--- a/lib/lp/code/xmlrpc/git.py
+++ b/lib/lp/code/xmlrpc/git.py
@@ -8,7 +8,9 @@ __all__ = [
'GitAPI',
]
+import logging
import sys
+import uuid
from pymacaroons import Macaroon
import six
@@ -109,6 +111,15 @@ def _can_internal_issuer_write(verified):
return verified.issuer_name == "code-import-job"
+class GitLoggerAdapter(logging.LoggerAdapter):
+ """A logger adapter that adds request-id information."""
+
+ def process(self, msg, kwargs):
+ if self.extra is not None and self.extra.get("request-id"):
+ msg = "[request-id=%s] %s" % (self.extra["request-id"], msg)
+ return msg, kwargs
+
+
@implementer(IGitAPI)
class GitAPI(LaunchpadXMLRPCView):
"""See `IGitAPI`."""
@@ -300,6 +311,14 @@ class GitAPI(LaunchpadXMLRPCView):
getUtility(IErrorReportingUtility).raising(sys.exc_info(), request)
raise faults.OopsOccurred("creating a Git repository", request.oopsid)
+ def _getLogger(self, request_id=None):
+ # XXX cjwatson 2019-10-16: Ideally we'd always have a request-id,
+ # but since that isn't yet the case, generate one if necessary.
+ if request_id is None:
+ request_id = uuid.uuid4()
+ return GitLoggerAdapter(
+ logging.getLogger(__name__), {"request-id": request_id})
+
def _createRepository(self, requester, path, clone_from=None):
try:
namespace, repository_name, target_default, owner_default = (
@@ -376,18 +395,36 @@ class GitAPI(LaunchpadXMLRPCView):
def translatePath(self, path, permission, auth_params):
"""See `IGitAPI`."""
- return run_with_login(
- _get_requester_id(auth_params), self._translatePath,
+ logger = self._getLogger(auth_params.get("request-id"))
+ requester_id = _get_requester_id(auth_params)
+ logger.info(
+ "Request received: translatePath('%s', '%s') for %s",
+ path, permission, requester_id)
+ result = run_with_login(
+ requester_id, self._translatePath,
six.ensure_text(path).strip("/"), permission, auth_params)
+ if isinstance(result, xmlrpc_client.Fault):
+ logger.error("translatePath failed: %r", result)
+ else:
+ # The results of path translation are not sensitive for logging
+ # purposes (they may refer to private artifacts, but contain no
+ # credentials).
+ logger.info("translatePath succeeded: %s", result)
+ return result
def notify(self, translated_path):
"""See `IGitAPI`."""
+ logger = self._getLogger()
+ logger.info("Request received: notify('%s')", translated_path)
repository = getUtility(IGitLookup).getByHostingPath(translated_path)
if repository is None:
- return faults.NotFound(
+ fault = faults.NotFound(
"No repository found for '%s'." % translated_path)
+ logger.error("notify failed: %r", fault)
+ return fault
getUtility(IGitRefScanJobSource).create(
removeSecurityProxy(repository))
+ logger.info("notify succeeded")
@return_fault
def _authenticateWithPassword(self, username, password):
@@ -411,7 +448,19 @@ class GitAPI(LaunchpadXMLRPCView):
def authenticateWithPassword(self, username, password):
"""See `IGitAPI`."""
- return self._authenticateWithPassword(username, password)
+ logger = self._getLogger()
+ logger.info(
+ "Request received: authenticateWithPassword('%s')", username)
+ result = self._authenticateWithPassword(username, password)
+ if isinstance(result, xmlrpc_client.Fault):
+ logger.error("authenticateWithPassword failed: %r", result)
+ else:
+ # The results of authentication may be sensitive, but we can at
+ # least log the authenticated user.
+ logger.info(
+ "authenticateWithPassword succeeded: %s",
+ result.get("uid", result.get("user")))
+ return result
def _renderPermissions(self, set_of_permissions):
"""Render a set of permission strings for XML-RPC output."""
@@ -470,9 +519,23 @@ class GitAPI(LaunchpadXMLRPCView):
def checkRefPermissions(self, translated_path, ref_paths, auth_params):
"""See `IGitAPI`."""
- return run_with_login(
- _get_requester_id(auth_params),
- self._checkRefPermissions,
- translated_path,
- ref_paths,
- auth_params)
+ logger = self._getLogger(auth_params.get("request-id"))
+ requester_id = _get_requester_id(auth_params)
+ logger.info(
+ "Request received: checkRefPermissions('%s', %s) for %s",
+ translated_path, [ref_path.data for ref_path in ref_paths],
+ requester_id)
+ result = run_with_login(
+ requester_id, self._checkRefPermissions,
+ translated_path, ref_paths, auth_params)
+ if isinstance(result, xmlrpc_client.Fault):
+ logger.error("checkRefPermissions failed: %r", result)
+ else:
+ # The results of ref permission checks are not sensitive for
+ # logging purposes (they may refer to private artifacts, but
+ # contain no credentials).
+ logger.info(
+ "checkRefPermissions succeeded: %s",
+ [(ref_path.data, permissions)
+ for ref_path, permissions in result])
+ return result
diff --git a/lib/lp/code/xmlrpc/tests/test_git.py b/lib/lp/code/xmlrpc/tests/test_git.py
index 757443a..f1846e7 100644
--- a/lib/lp/code/xmlrpc/tests/test_git.py
+++ b/lib/lp/code/xmlrpc/tests/test_git.py
@@ -5,6 +5,9 @@
__metaclass__ = type
+import uuid
+
+from fixtures import FakeLogger
from pymacaroons import Macaroon
import six
from six.moves import xmlrpc_client
@@ -13,6 +16,7 @@ from testtools.matchers import (
IsInstance,
MatchesAll,
MatchesListwise,
+ MatchesRegex,
MatchesSetwise,
MatchesStructure,
)
@@ -67,7 +71,10 @@ from lp.xmlrpc import faults
def _make_auth_params(requester, can_authenticate=False, macaroon_raw=None):
- auth_params = {"can-authenticate": can_authenticate}
+ auth_params = {
+ "can-authenticate": can_authenticate,
+ "request-id": str(uuid.uuid4()),
+ }
if requester == LAUNCHPAD_SERVICES:
auth_params["user"] = LAUNCHPAD_SERVICES
elif requester is not None:
@@ -146,21 +153,42 @@ class TestGitAPIMixin:
self.hosting_fixture = self.useFixture(GitHostingFixture())
self.repository_set = getUtility(IGitRepositorySet)
- def assertFault(self, expected_fault, func, *args, **kwargs):
+ def assertFault(self, expected_fault, request_id, func_name,
+ *args, **kwargs):
"""Assert that a call raises the expected fault."""
- fault = self.assertRaises(xmlrpc_client.Fault, func, *args, **kwargs)
- self.assertThat(fault, MatchesFault(expected_fault))
+ with FakeLogger() as logger:
+ fault = self.assertRaises(
+ xmlrpc_client.Fault, getattr(self.git_api, func_name),
+ *args, **kwargs)
+ self.assertThat(fault, MatchesFault(expected_fault))
+ self.assertThat(logger.output, MatchesRegex(
+ r"\[request-id=%s\] Request received: %s.*\n"
+ r"\[request-id=%s\] %s failed: .* %s:.*" % (
+ request_id or ".*", func_name,
+ request_id or ".*", func_name, fault.faultCode)))
return fault
+ def assertDoesNotFault(self, request_id, func_name, *args, **kwargs):
+ """Assert that a call does not raise a fault."""
+ with FakeLogger() as logger:
+ results = getattr(self.git_api, func_name)(*args, **kwargs)
+ self.assertThat(logger.output, MatchesRegex(
+ r"\[request-id=%s\] Request received: %s.*\n"
+ r"\[request-id=%s\] %s succeeded.*" % (
+ request_id or ".*", func_name,
+ request_id or ".*", func_name)))
+ return results
+
def assertGitRepositoryNotFound(self, requester, path, permission="read",
can_authenticate=False, macaroon_raw=None):
"""Assert that the given path cannot be translated."""
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate,
macaroon_raw=macaroon_raw)
+ request_id = auth_params["request-id"]
self.assertFault(
- faults.GitRepositoryNotFound(path.strip("/")),
- self.git_api.translatePath, path, permission, auth_params)
+ faults.GitRepositoryNotFound(path.strip("/")), request_id,
+ "translatePath", path, permission, auth_params)
def assertPermissionDenied(self, requester, path,
message="Permission denied.",
@@ -170,9 +198,10 @@ class TestGitAPIMixin:
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate,
macaroon_raw=macaroon_raw)
+ request_id = auth_params["request-id"]
self.assertFault(
- faults.PermissionDenied(message),
- self.git_api.translatePath, path, permission, auth_params)
+ faults.PermissionDenied(message), request_id,
+ "translatePath", path, permission, auth_params)
def assertUnauthorized(self, requester, path,
message="Authorisation required.",
@@ -182,18 +211,20 @@ class TestGitAPIMixin:
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate,
macaroon_raw=macaroon_raw)
+ request_id = auth_params["request-id"]
self.assertFault(
- faults.Unauthorized(message),
- self.git_api.translatePath, path, permission, auth_params)
+ faults.Unauthorized(message), request_id,
+ "translatePath", path, permission, auth_params)
def assertNotFound(self, requester, path, message, permission="read",
can_authenticate=False):
"""Assert that looking at the given path returns NotFound."""
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate)
+ request_id = auth_params["request-id"]
self.assertFault(
- faults.NotFound(message),
- self.git_api.translatePath, path, permission, auth_params)
+ faults.NotFound(message), request_id,
+ "translatePath", path, permission, auth_params)
def assertInvalidSourcePackageName(self, requester, path, name,
permission="read",
@@ -202,27 +233,30 @@ class TestGitAPIMixin:
InvalidSourcePackageName."""
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate)
+ request_id = auth_params["request-id"]
self.assertFault(
- faults.InvalidSourcePackageName(name),
- self.git_api.translatePath, path, permission, auth_params)
+ faults.InvalidSourcePackageName(name), request_id,
+ "translatePath", path, permission, auth_params)
def assertInvalidBranchName(self, requester, path, message,
permission="read", can_authenticate=False):
"""Assert that looking at the given path returns InvalidBranchName."""
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate)
+ request_id = auth_params["request-id"]
self.assertFault(
- faults.InvalidBranchName(Exception(message)),
- self.git_api.translatePath, path, permission, auth_params)
+ faults.InvalidBranchName(Exception(message)), request_id,
+ "translatePath", path, permission, auth_params)
def assertOopsOccurred(self, requester, path,
permission="read", can_authenticate=False):
"""Assert that looking at the given path OOPSes."""
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate)
+ request_id = auth_params["request-id"]
fault = self.assertFault(
- faults.OopsOccurred,
- self.git_api.translatePath, path, permission, auth_params)
+ faults.OopsOccurred, request_id,
+ "translatePath", path, permission, auth_params)
prefix = (
"An unexpected error has occurred while creating a Git "
"repository. Please report a Launchpad bug and quote: ")
@@ -235,7 +269,9 @@ class TestGitAPIMixin:
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate,
macaroon_raw=macaroon_raw)
- translation = self.git_api.translatePath(path, permission, auth_params)
+ request_id = auth_params["request-id"]
+ translation = self.assertDoesNotFault(
+ request_id, "translatePath", path, permission, auth_params)
login(ANONYMOUS)
self.assertEqual(
{"path": removeSecurityProxy(repository).getInternalPath(),
@@ -246,7 +282,9 @@ class TestGitAPIMixin:
private=False):
auth_params = _make_auth_params(
requester, can_authenticate=can_authenticate)
- translation = self.git_api.translatePath(path, "write", auth_params)
+ request_id = auth_params["request-id"]
+ translation = self.assertDoesNotFault(
+ request_id, "translatePath", path, "write", auth_params)
login(ANONYMOUS)
repository = getUtility(IGitRepositorySet).getByPath(
requester, path.lstrip("/"))
@@ -272,10 +310,12 @@ class TestGitAPIMixin:
def assertHasRefPermissions(self, requester, repository, ref_paths,
permissions, macaroon_raw=None):
auth_params = _make_auth_params(requester, macaroon_raw=macaroon_raw)
+ request_id = auth_params["request-id"]
translated_path = removeSecurityProxy(repository).getInternalPath()
ref_paths = [
xmlrpc_client.Binary(ref_path) for ref_path in ref_paths]
- results = self.git_api.checkRefPermissions(
+ results = self.assertDoesNotFault(
+ request_id, "checkRefPermissions",
translated_path, ref_paths, auth_params)
self.assertThat(results, MatchesSetwise(*(
MatchesListwise([
@@ -593,9 +633,8 @@ class TestGitAPIMixin:
def test_checkRefPermissions_nonexistent_repository(self):
requester = self.factory.makePerson()
self.assertFault(
- faults.GitRepositoryNotFound("nonexistent"),
- self.git_api.checkRefPermissions,
- "nonexistent", [], {"uid": requester.id})
+ faults.GitRepositoryNotFound("nonexistent"), None,
+ "checkRefPermissions", "nonexistent", [], {"uid": requester.id})
class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
@@ -1169,7 +1208,8 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
def test_notify(self):
# The notify call creates a GitRefScanJob.
repository = self.factory.makeGitRepository()
- self.assertIsNone(self.git_api.notify(repository.getInternalPath()))
+ self.assertIsNone(self.assertDoesNotFault(
+ None, "notify", repository.getInternalPath()))
job_source = getUtility(IGitRefScanJobSource)
[job] = list(job_source.iterReady())
self.assertEqual(repository, job.repository)
@@ -1177,7 +1217,7 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
def test_notify_missing_repository(self):
# A notify call on a non-existent repository returns a fault and
# does not create a job.
- self.assertFault(faults.NotFound, self.git_api.notify, "10000")
+ self.assertFault(faults.NotFound, None, "notify", "10000")
job_source = getUtility(IGitRefScanJobSource)
self.assertEqual([], list(job_source.iterReady()))
@@ -1187,15 +1227,15 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
repository = self.factory.makeGitRepository(
information_type=InformationType.PRIVATESECURITY)
path = repository.getInternalPath()
- self.assertIsNone(self.git_api.notify(path))
+ self.assertIsNone(self.assertDoesNotFault(None, "notify", path))
job_source = getUtility(IGitRefScanJobSource)
[job] = list(job_source.iterReady())
self.assertEqual(repository, job.repository)
def test_authenticateWithPassword(self):
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword, "foo", "bar")
+ faults.Unauthorized, None,
+ "authenticateWithPassword", "foo", "bar")
def test_authenticateWithPassword_code_import(self):
self.pushConfig(
@@ -1208,15 +1248,15 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
macaroon = removeSecurityProxy(issuer).issueMacaroon(job)
self.assertEqual(
{"macaroon": macaroon.serialize(), "user": "+launchpad-services"},
- self.git_api.authenticateWithPassword("", macaroon.serialize()))
+ self.assertDoesNotFault(
+ None, "authenticateWithPassword", "", macaroon.serialize()))
other_macaroon = Macaroon(identifier="another", key="another-secret")
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword,
- "", other_macaroon.serialize())
+ faults.Unauthorized, None,
+ "authenticateWithPassword", "", other_macaroon.serialize())
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword, "", "nonsense")
+ faults.Unauthorized, None,
+ "authenticateWithPassword", "", "nonsense")
def test_authenticateWithPassword_private_snap_build(self):
self.useFixture(FeatureFixture(SNAP_TESTING_FLAGS))
@@ -1231,15 +1271,15 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
macaroon = removeSecurityProxy(issuer).issueMacaroon(build)
self.assertEqual(
{"macaroon": macaroon.serialize(), "user": "+launchpad-services"},
- self.git_api.authenticateWithPassword("", macaroon.serialize()))
+ self.assertDoesNotFault(
+ None, "authenticateWithPassword", "", macaroon.serialize()))
other_macaroon = Macaroon(identifier="another", key="another-secret")
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword,
- "", other_macaroon.serialize())
+ faults.Unauthorized, None,
+ "authenticateWithPassword", "", other_macaroon.serialize())
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword, "", "nonsense")
+ faults.Unauthorized, None,
+ "authenticateWithPassword", "", "nonsense")
def test_authenticateWithPassword_user_macaroon(self):
# A user with a suitable macaroon can authenticate using it, in
@@ -1252,23 +1292,23 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
self.factory.makeGitRepository(owner=requester), user=requester)
self.assertEqual(
{"macaroon": macaroon.serialize(), "uid": requester.id},
- self.git_api.authenticateWithPassword(
+ self.assertDoesNotFault(
+ None, "authenticateWithPassword",
requester.name, macaroon.serialize()))
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword, "", macaroon.serialize())
+ faults.Unauthorized, None,
+ "authenticateWithPassword", "", macaroon.serialize())
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword,
- "nonexistent", macaroon.serialize())
+ faults.Unauthorized, None,
+ "authenticateWithPassword", "nonexistent", macaroon.serialize())
other_macaroon = Macaroon(identifier="another", key="another-secret")
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword,
+ faults.Unauthorized, None,
+ "authenticateWithPassword",
requester.name, other_macaroon.serialize())
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword, requester.name, "nonsense")
+ faults.Unauthorized, None,
+ "authenticateWithPassword", requester.name, "nonsense")
def test_authenticateWithPassword_user_mismatch(self):
# authenticateWithPassword refuses macaroons in the case where the
@@ -1300,7 +1340,8 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
expected_auth_params["uid"] = requester.id
self.assertEqual(
expected_auth_params,
- self.git_api.authenticateWithPassword(
+ self.assertDoesNotFault(
+ None, "authenticateWithPassword",
name, macaroon.serialize()))
for requester in unauthorized:
login(ANONYMOUS)
@@ -1308,9 +1349,8 @@ class TestGitAPI(TestGitAPIMixin, TestCaseWithFactory):
requester if requester == LAUNCHPAD_SERVICES
else requester.name)
self.assertFault(
- faults.Unauthorized,
- self.git_api.authenticateWithPassword,
- name, macaroon.serialize())
+ faults.Unauthorized, None,
+ "authenticateWithPassword", name, macaroon.serialize())
def test_checkRefPermissions_code_import(self):
# A code import worker with a suitable macaroon has repository owner
