mercari / grpc-federation

gRPC Federation generates a gRPC server by writing a custom option in Protocol Buffers
MIT License
318 stars 13 forks source link

Fix logger propaggation #206

Closed utahta closed 4 months ago

utahta commented 4 months ago

When a field is added using grpc.federation.log.add, we expect it to be output to the log of the message in which it is defined, but it is actually also output to the log of the upstream message. To prevent this, we also call grpcfed.WithLogger in the resolver function.

e.g. Suppose we have the following definition:

message GetPostResponse {
  option (.grpc.federation.message) = {
    def {
      name: "post"
      message {
        name: "Post"
        args { name: "id", by: "$.id" }
      }
    }
  };
  Post post = 1 [(grpc.federation.field).by = "post"];
}

message Post {
  option (grpc.federation.message) = {
    def [
      {
        name: "res"
        call {
          method: "post.PostService/GetPost"
          request { field: "id", by: "$.id" }      
        }
      },
      { name: "post", by: "res.post", autobind: true },
      { by: "grpc.federation.log.add({'test_post_id': post.id})" }
    ]
  };
  string id = 1;
  string title = 2;
  string content = 3;
}

test_post_id field is expected to be output only in the log of Post message, but actualy it is also output in the log of GetPostResponse message (last line)

expected:

{"time":"2024-06-28T19:14:04.674+09:00","level":"DEBUG","msg":"resolve federation.GetPostResponse","message_args":{"id":"foo"}}
{"time":"2024-06-28T19:14:04.681815+09:00","level":"DEBUG","msg":"resolve federation.Post","message_args":{"id":"foo"}}
{"time":"2024-06-28T19:14:04.682981+09:00","level":"DEBUG","msg":"call post.PostService/GetPost","post.GetPostRequest":{"id":"foo"}}
{"time":"2024-06-28T19:14:04.688373+09:00","level":"DEBUG","msg":"resolved federation.Post","test_post_id":"foo","federation.Post":{"id":"foo","title":"foo","content":"bar"}}
{"time":"2024-06-28T19:14:04.689465+09:00","level":"DEBUG","msg":"resolved federation.GetPostResponse","federation.GetPostResponse":{"post":{"id":"foo","title":"foo","content":"bar"}}}

actual:

{"time":"2024-06-28T19:14:38.854809+09:00","level":"DEBUG","msg":"resolve federation.GetPostResponse","message_args":{"id":"foo"}}
{"time":"2024-06-28T19:14:38.863336+09:00","level":"DEBUG","msg":"resolve federation.Post","message_args":{"id":"foo"}}
{"time":"2024-06-28T19:14:38.864611+09:00","level":"DEBUG","msg":"call post.PostService/GetPost","post.GetPostRequest":{"id":"foo"}}
{"time":"2024-06-28T19:14:38.871586+09:00","level":"DEBUG","msg":"resolved federation.Post","test_post_id":"foo","federation.Post":{"id":"foo","title":"foo","content":"bar"}}
{"time":"2024-06-28T19:14:38.872723+09:00","level":"DEBUG","msg":"resolved federation.GetPostResponse","test_post_id":"foo","federation.GetPostResponse":{"post":{"id":"foo","title":"foo","content":"bar"}}}
github-actions[bot] commented 4 months ago

Code Metrics Report

main (9ece0c7) #206 (b779abf) +/-
Coverage 65.0% 65.0% 0.0%
Code to Test Ratio 1:0.3 1:0.3 -0.0
Test Execution Time 7m13s 7m4s -9s
Details ``` diff | | main (9ece0c7) | #206 (b779abf) | +/- | |---------------------|----------------|----------------|------| | Coverage | 65.0% | 65.0% | 0.0% | | Files | 69 | 69 | 0 | | Lines | 11475 | 11475 | 0 | | Covered | 7457 | 7457 | 0 | - | Code to Test Ratio | 1:0.3 | 1:0.3 | -0.0 | | Code | 36529 | 36583 | +54 | | Test | 12567 | 12567 | 0 | + | Test Execution Time | 7m13s | 7m4s | -9s | ```

Reported by octocov

github-actions[bot] commented 4 months ago

Code Metrics Report

main (9ece0c7) #206 (a4dc5a2) +/-
Coverage 65.0% 65.0% 0.0%
Code to Test Ratio 1:0.3 1:0.3 -0.0
Test Execution Time 7m13s 7m7s -6s
Details ``` diff | | main (9ece0c7) | #206 (a4dc5a2) | +/- | |---------------------|----------------|----------------|------| | Coverage | 65.0% | 65.0% | 0.0% | | Files | 69 | 69 | 0 | | Lines | 11475 | 11475 | 0 | | Covered | 7457 | 7457 | 0 | - | Code to Test Ratio | 1:0.3 | 1:0.3 | -0.0 | | Code | 36529 | 36583 | +54 | | Test | 12567 | 12567 | 0 | + | Test Execution Time | 7m13s | 7m7s | -6s | ```

Reported by octocov