Track feature flags used for RPC call

Feature flags allow us to introduce new functionality with iterative approach. We can introduce a new feature and protect its execution with a feature flag, so we could control when the new code will be executed. It helps a lot in testing on gitlab.com and reduce time of service unavailability. It is allowed to enable feature in percents. So we could verify it on a small subset of all requests. The hard part with it is to understand if the RPC was called with or without a feature flag enabled.

The new interceptors for gRPC endpoints extend logging context with the list of feature flags used during RPC invocation. As it is now part of the logging context the value will be used in each log entry. It seems more reasonable then adding additional log entry as there are not many logs are written by the service while it operates without issues.

Praefect log:

2020-12-30_14:09:11.45266 [35mpraefect              : [0mtime="2020-12-30T16:09:11+02:00" level=info msg="finished streaming call with code OK" correlation_id=1fMQ8Cd6y1 feature_flags="go-user-squash:false distributed-reads:true go-fetch-remote:true" grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-sidekiq grpc.meta.deadline_type=unknown grpc.method=ListFiles grpc.request.deadline="2020-12-30T16:09:41+02:00" grpc.request.fullMethod=/gitaly.CommitService/ListFiles grpc.service=gitaly.CommitService grpc.start_time="2020-12-30T16:09:11+02:00" grpc.time_ms=18.351 peer.address= pid=15186 relative_path=@hashed/b7/a5/b7a56873cd771f2c446d369b649430b65a756ba278ff97ec81bb6f55b2e73569.git span.kind=server system=grpc virtual_storage=default

Gitaly log:

2020-12-30_14:09:14.04574 [36mpraefect-gitaly-0     : [0m{"correlation_id":"1fMQ8Cd6y1","feature_flags":"go-fetch-remote:true distributed-reads:true go-user-squash:false","grpc.code":"OK","grpc.meta.auth_version":"v2","grpc.meta.client_name":"gitlab-sidekiq","grpc.meta.deadline_type":"unknown","grpc.method":"CommitLanguages","grpc.request.deadline":"2020-12-30T22:09:10+02:00","grpc.request.fullMethod":"/gitaly.CommitService/CommitLanguages","grpc.request.glProjectPath":"root/fff","grpc.request.glRepository":"project-25","grpc.request.repoPath":"@hashed/b7/a5/b7a56873cd771f2c446d369b649430b65a756ba278ff97ec81bb6f55b2e73569.git","grpc.request.repoStorage":"praefect-internal-0","grpc.request.topLevelGroup":"@hashed","grpc.service":"gitaly.CommitService","grpc.start_time":"2020-12-30T16:09:10+02:00","grpc.time_ms":3548.65,"level":"info","msg":"finished unary call with code OK","peer.address":"","pid":20573,"span.kind":"server","system":"grpc","time":"2020-12-30T16:09:14.045Z"}

Closes: #3249 (closed)

Edited by Pavlo Strokov

Merge request reports

Loading