diff --git a/hgitaly/interceptors.py b/hgitaly/interceptors.py index c5a8ff21803651cb3d243c36ac1e32741eaf045f_aGdpdGFseS9pbnRlcmNlcHRvcnMucHk=..1d29e1b9b6fefb0c93052f2ea88b92be6d4cf83c_aGdpdGFseS9pbnRlcmNlcHRvcnMucHk= 100644 --- a/hgitaly/interceptors.py +++ b/hgitaly/interceptors.py @@ -15,4 +15,5 @@ from grpc_interceptor import ServerInterceptor from . import message +from .logging import LoggerAdapter @@ -18,5 +19,6 @@ -logger = logging.getLogger(__name__) + +base_logger = logging.getLogger(__name__) def is_streaming(message) -> bool: @@ -53,6 +55,7 @@ # of course it would be great to change the logger depending # on the service, but with (H)Gitaly naming conventions, the class # name of the request contains all the information. + logger = LoggerAdapter(base_logger, context) logger.debug("Starting to process RPC %r", message.Logging(first)) response = method(request, context) diff --git a/hgitaly/logging.py b/hgitaly/logging.py new file mode 100644 index 0000000000000000000000000000000000000000..1d29e1b9b6fefb0c93052f2ea88b92be6d4cf83c_aGdpdGFseS9sb2dnaW5nLnB5 --- /dev/null +++ b/hgitaly/logging.py @@ -0,0 +1,41 @@ +# Copyright 2023 Georges Racinet <georges.racinet@octobus.net> +# +# This software may be used and distributed according to the terms of the +# GNU General Public License version 2 or any later version. +# +# SPDX-License-Identifier: GPL-2.0-or-later +import logging + + +_missing = object() + +CORRELATION_ID_MD_KEY = 'x-gitlab-correlation-id' + + +def extract_correlation(context): + """Extract and cache correlation info for a gRPC context.""" + + corr_id = getattr(context, 'correlation_id', _missing) + if corr_id is _missing: + for md in context.invocation_metadata(): + if md.key == CORRELATION_ID_MD_KEY: + corr_id = md.value + break + else: + # avoid searching again + corr_id = None + context.correlation_id = corr_id + return corr_id + + +class LoggerAdapter(logging.LoggerAdapter): + + def __init__(self, logger, context): + self.grpc_context = context + self.logger = logger + + def process(self, msg, kwargs): + # set on context by interceptor + kwargs['extra'] = {'correlation_id': + extract_correlation(self.grpc_context)} + return msg, kwargs diff --git a/hgitaly/service/tests/fixture.py b/hgitaly/service/tests/fixture.py index c5a8ff21803651cb3d243c36ac1e32741eaf045f_aGdpdGFseS9zZXJ2aWNlL3Rlc3RzL2ZpeHR1cmUucHk=..1d29e1b9b6fefb0c93052f2ea88b92be6d4cf83c_aGdpdGFseS9zZXJ2aWNlL3Rlc3RzL2ZpeHR1cmUucHk= 100644 --- a/hgitaly/service/tests/fixture.py +++ b/hgitaly/service/tests/fixture.py @@ -5,6 +5,7 @@ # # SPDX-License-Identifier: GPL-2.0-or-later import attr +import logging import shutil from hgitaly import feature @@ -8,6 +9,7 @@ import shutil from hgitaly import feature +from hgitaly.logging import CORRELATION_ID_MD_KEY from hgitaly.stub.shared_pb2 import Repository from heptapod.testhelpers import ( @@ -16,6 +18,10 @@ from hgitaly.tests.common import ( make_empty_repo_uniform, ) +from hgitaly.interceptors import base_logger as intercept_logger + +# for coverage of hgitaly.logging +intercept_logger.setLevel(logging.DEBUG) @attr.s @@ -75,6 +81,10 @@ self.rpc('MyRpc', request) """ + correlation_id = attr.ib(default=None) + """Correlation id, to test/exert the logging system + """ + repo_factory = attr.ib(default=make_empty_repo_uniform) """Callable with the same signature as :func:`make_empty_repo_uniform`. """ @@ -148,4 +158,8 @@ Takes care of feature flags only as of this writing, but could also be useful with other metadata (correlation id etc.) """ - return feature.as_grpc_metadata(self.feature_flags) + metadata = feature.as_grpc_metadata(self.feature_flags) + corr_id = self.correlation_id + if corr_id is not None: + metadata.append((CORRELATION_ID_MD_KEY, corr_id)) + return metadata diff --git a/hgitaly/service/tests/test_commit.py b/hgitaly/service/tests/test_commit.py index c5a8ff21803651cb3d243c36ac1e32741eaf045f_aGdpdGFseS9zZXJ2aWNlL3Rlc3RzL3Rlc3RfY29tbWl0LnB5..1d29e1b9b6fefb0c93052f2ea88b92be6d4cf83c_aGdpdGFseS9zZXJ2aWNlL3Rlc3RzL3Rlc3RfY29tbWl0LnB5 100644 --- a/hgitaly/service/tests/test_commit.py +++ b/hgitaly/service/tests/test_commit.py @@ -68,8 +68,9 @@ ).value def find_commit(self, revision): - return self.stub.FindCommit( - FindCommitRequest(repository=self.grpc_repo, revision=revision)) + return self.rpc('FindCommit', + FindCommitRequest(repository=self.grpc_repo, + revision=revision)) def find_commits(self, limit=10, **opts): request = FindCommitsRequest(repository=self.grpc_repo, @@ -169,6 +170,7 @@ # over branches def test_find_commit(commit_fixture_empty_repo): fixture = commit_fixture_empty_repo + fixture.correlation_id = "1111-correlation" wrapper = fixture.repo_wrapper find_commit = fixture.find_commit