3

I am trying to connect a Flutter app to gRPC server. It used to work fine in my older laptop, but now I always get this error when I try to make a request to an endpoint:

gRPC Error (code: 13, codeName: INTERNAL, message: grpc: error unmarshalling request: string field contains invalid UTF-8, details: [], rawResponse: null)

when I use another gRPC client, such as bloomRPC, the call is successful and I get the correct data. The Flutter app call does not even reach the endpoint service (I put a println there to test it, and it does not print anything when I make a call from the Flutter app, but it does print it when using bloomRPC).

This is my client connection code:

class GrpcClient {
  late ClientChannel client;
  static final GrpcClient _connection = GrpcClient._connect();

  factory GrpcClient() => _connection;
  
  GrpcClient._connect(){
    client = ClientChannel(
     "10.0.2.2",
      port: 8080,
      options: ChannelOptions(credentials: ChannelCredentials.insecure(), connectionTimeout:Duration(seconds: 10))
    );

  }
}

I run the server with GODEBUG=http2debug=2 go run .. I got this output when I made the call from Bloom:

2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote SETTINGS len=6, settings: MAX_FRAME_SIZE=16384
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read SETTINGS len=36, settings: ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=4194304, MAX_FRAME_SIZE=4194304, MAX_HEADER_LIST_SIZE=8192, UNKNOWN_SETTING_65027=1
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read WINDOW_UPDATE len=4 (conn) incr=4128769
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read PING len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x00"
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote SETTINGS flags=ACK len=0
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read HEADERS flags=END_HEADERS stream=1 len=259
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote PING flags=ACK len=8 ping="\x00\x00\x00\x00\x00\x00\x00\x00"
2021/12/27 22:23:52 http2: decoded hpack field header field ":scheme" = "http"
2021/12/27 22:23:52 http2: decoded hpack field header field ":method" = "POST"
2021/12/27 22:23:52 http2: decoded hpack field header field ":authority" = "localhost:8080"
2021/12/27 22:23:52 http2: decoded hpack field header field ":path" = "/protofiles.UserService/GetUserById"
2021/12/27 22:23:52 http2: decoded hpack field header field "te" = "trailers"
2021/12/27 22:23:52 http2: decoded hpack field header field "content-type" = "application/grpc"
2021/12/27 22:23:52 http2: decoded hpack field header field "user-agent" = "grpc-node/1.24.7 grpc-c/8.0.0 (windows; chttp2; ganges)"
2021/12/27 22:23:52 http2: decoded hpack field header field "grpc-accept-encoding" = "identity,deflate,gzip"
2021/12/27 22:23:52 http2: decoded hpack field header field "accept-encoding" = "identity,gzip"
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read WINDOW_UPDATE stream=1 len=4 incr=5
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read DATA flags=END_STREAM stream=1 len=122 data="\x00\x00\x00\x00u\ns\b\x05\x12\x05Hello\x1a$1bcc4186-3a63-4a22-8dac-c144d6d0eb49\"\x05Hello*\x05Hello0\x00:\x04\b\x14\x10\nB\x05HelloJ\x05HelloR\x04\b\x14\x10\nZ\b\b\x14\x10\x01\x18\x01 \x00`\x14h\x14p\x14x\x14\x82\x01\"
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read WINDOW_UPDATE len=4 (conn) incr=5
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote WINDOW_UPDATE len=4 (conn) incr=122
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: read SETTINGS flags=ACK len=0
Hello
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote HEADERS flags=END_HEADERS stream=1 len=14
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote DATA stream=1 len=192 data="\x00\x00\x00\x00\xbb\n\xb8\x01\b\x05\x12\tHajjivsky
2021/12/27 22:23:52 http2: Framer 0xc0000a6000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=24

And this output from the Dart application:

2021/12/27 22:25:25 http2: Framer 0xc0002b2000: wrote SETTINGS len=6, settings: MAX_FRAME_SIZE=16384
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: read SETTINGS len=6, settings: ENABLE_PUSH=0
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: wrote SETTINGS flags=ACK len=0
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: read SETTINGS flags=ACK len=0
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: read HEADERS flags=END_HEADERS stream=1 len=169
2021/12/27 22:25:25 http2: decoded hpack field header field ":method" = "POST"
2021/12/27 22:25:25 http2: decoded hpack field header field ":scheme" = "http"
2021/12/27 22:25:25 http2: decoded hpack field header field ":path" = "/protofiles.UserService/GetUserById"
2021/12/27 22:25:25 http2: decoded hpack field header field ":authority" = "10.0.2.2:8080"
2021/12/27 22:25:25 http2: decoded hpack field header field "content-type" = "application/grpc"
2021/12/27 22:25:25 http2: decoded hpack field header field "te" = "trailers"
2021/12/27 22:25:25 http2: decoded hpack field header field "user-agent" = "dart-grpc/2.0.0"
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: read DATA stream=1 len=69 data="\x00\x00\x00\x00@\n>\b\x05\x12\x00\x1a\x00\"\x00(\x002\f\b\xa4\xa6\xa8\x8e\x06\x10\xa0\xb7\x93\xf1\x01:\x00B\x00J\f\b\xa4\xa6\xa8\x8e\x06\x10\xf0ɒ\xf1\x01R\b\b\x00\x10\x00\x18\x00 \x00X\x00`\x00h\x00p\x00z\x00"
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: wrote WINDOW_UPDATE len=4 (conn) incr=69
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: read DATA flags=END_STREAM stream=1 len=0 data=""
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=90
2021/12/27 22:25:25 http2: Framer 0xc0002b2000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"

This is the proto message & endpoint:

message User{
    int64 id = 1;
    string username = 2;
    string auth_user_id = 3;
    string email = 4;
    string display_name = 5;
    Gender gender = 6;
}

func (u *UserService) GetUserById(ctx context.Context, in *protofiles.GetUserRequest) (*protofiles.GetUserResponse, error) {
    user, err := u.store.GetByID(in.User.Id)
    if err != nil {
        return &protofiles.GetUserResponse{}, err
    }
    return &protofiles.GetUserResponse{User: models.UserHelper.ToProto(user)}, nil
}
Ali Alhajji
  • 174
  • 2
  • 12
  • Is it possible that one of the string fields in the message does contain invalid UTF-8? Are you demonstrably able to send exactly the same message using Bloom as you are using Flutter (I think Bloom uses a NodeJS runtime rather than Dart so it mostly shows that another gRPC client can submit the same message without error)? Is it possible that you're using a different release|version of Dart|Flutter gRPC? What language is the server written in? (It may help provide guidance in logging the received message to help diagnose). – DazWilkin Dec 27 '21 at 01:53
  • Yes I am sending the same message in Bloom and I get all valid UTF-8. As I mentioned in the post, I added a "prinln" line in the server function so that I can make sure the request is reaching to the function, but nothing was printed out which means the method has not even been invoked. – Ali Alhajji Dec 27 '21 at 17:59
  • The server is written in Go. I am using the same Flutter & Dart versions that I used to have when everything was working fine in my other device. I cannot get to what exactly is the problem here. – Ali Alhajji Dec 27 '21 at 18:02
  • If the server is unable to unmarshal the incoming request, your server method will not be invoked. You can add debugging statements to your Golang server: `GODEBUG=http2debug=2 go run ...` to get detailed logging on incoming requests – DazWilkin Dec 27 '21 at 18:43
  • It would be helpful of you to include the proto and an example message that fails in your question. – DazWilkin Dec 27 '21 at 18:46
  • Please don't post answers that aren't. You may edit your question and revise it. – DazWilkin Dec 27 '21 at 23:16
  • Eye-balling the two outputs, the `read DATA ... data` values look entirely different. I find it hard to believe that these represent the same message. – DazWilkin Dec 27 '21 at 23:20
  • Thanks. I added the logs to the question. I agree with you. The data are missing, it seems that the client is not sending any data to the server. Which is weird because the same code is working fine on another machine. I will dig more into it. – Ali Alhajji Dec 28 '21 at 15:00
  • I'm out of ideas. At this point, you can debug the incoming request. Something is different between the runtime on your old and new machines. That's almost impossible for me to discern. I'd continue to try to isolate differences and see whether anything obvious arises. – DazWilkin Dec 28 '21 at 17:34
  • Thank you so much. That was really helpful. I will carry on from here and I'll let you know if I find anything. – Ali Alhajji Dec 28 '21 at 17:41
  • Finally it's working.. – Ali Alhajji Dec 29 '21 at 17:51

1 Answers1

6

After several hours of trial and error, I finally figured out what the problem was, it like many other bugs it turned out to be a stupid one. The order of the tags in the proto file's message has been changed (a new field was added at the top and all of the other fields were pushed downward). The server was using the new definition, while the client was using the old one. When the client tried to call an endpoint, the tags did not match.

All I had to do is re-generate the files for the client stub.

Ali Alhajji
  • 174
  • 2
  • 12
  • 1
    I'm pleased to see you solved your issue. IIUC there was a field renumbering change that caused the break. As you've seen, renumbering is discouraged. See [Updating a message type](https://developers.google.com/protocol-buffers/docs/proto3#updating) – DazWilkin Dec 29 '21 at 17:57
  • 1
    That's correct. Actually I'm working with a friend on the same project. He changed the numbering and I did not regenerate the new client stub, which caused the mismatch. – Ali Alhajji Dec 30 '21 at 12:59
  • 1
    Thanks so much for posting it here, you saved me several hours of trial and error – Sergey Kolodyazhnyy Dec 06 '22 at 00:20