GRPC丢包之路

GRPC是Google开源的一个高性能、跨语言的RPC框架,基于HTTP2协议,基于protobuf-3.x,基于Netty-4.x。

最近开发一个公司的游戏项目,采用分布式的服务器架构,内部服务之间均采用GRPC进行通信。但是在测试过程中发现一个重大的bug,偶现丢包

前置信息:ServerA(作为grpc的client端)通过futureStub异步调用ServerB(作为server端)。

查看日志发现,client中有调用发送请求的日志,但server端却没有任何收到请求的日志。于是怀疑server在接收请求的过程中吃掉了异常,对整个过程加上try-catch,然而并没有任何发现,于是怀疑根本没有收到请求。通过tcpdump抓包后发现确实是client没发包到网络层,由此确定了是client端问题。

怀疑是grpc的futureStub有bug,于是在finally中加入future.get()打印出调用结果。结果一天下来一直没有发现任何丢包,”完美“。懵逼了,去掉finally中的future get以后又出现丢包。这个时候,直觉判断,由于调用futue.get()会block当前线程,所以不会出现丢包,而不block就会丢包。有种接近真相的感觉。检查代码后发现client端创建stub的时候没有指定线程池,grpc会默认使用当前线程,结合偶现的表现,觉得非常像是线程在异步发送的过程中被销毁导致。

然而,指定线程池以后,依旧发现丢包。无奈之下只有开始查看grpc源码,并打印出grpc的日志。在日志中发现了如下错误:

1
2
3
----------------OUTBOUND--------------------
[id: 0x7dee8b32, L:/10.82.7.14:60365 - R:/10.82.7.14:9001] RST_STREAM: streamId=4025, errorCode=8
------------------------------------

看到errorCode=8,并结合grpc源码中对io.grpc.Status的定义:

1
2
3
4
5
/**
* Some resource has been exhausted, perhaps a per-user quota, or
* perhaps the entire file system is out of space.
*/
RESOURCE_EXHAUSTED(8),

推断是由于系统文件句柄资源耗尽导致,查看服务器系统文件句柄限制为65535,而进程打开的限制远不止这么多。于是找sa将文件句柄限制改为100w,然后信心满满的重启了全部服务,重新进行测试。结果很快又发现了丢包,内心崩溃!

由于当future.get()方法阻塞线程时,就不会出现丢包,无法重现。于是想到把futureStub改为stub,在保持异步的同时,通过observer回调来观察调用结果,这次在回调的onError方法中发现了如下异常:

1
2
3
4
5
6
7
8
9
10
11
12
13
CANCELLED,
io.grpc.Status.asRuntimeException(Status.java:543),
io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:395),
io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:426),
io.grpc.internal.ClientCallImpl.access$100(ClientCallImpl.java:76),
io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:512),
io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:429),
io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:544),
io.grpc.internal.ContextRunnable.run(ContextRunnable.java:52),
io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:117),
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142),
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617),
java.lang.Thread.run(Thread.java:745

终于发现原来是这个call被grpc在底层cancel掉了。查代码发现原来上面的errorCode=8是指http2的code定义:

1
2
3
4
5
6
/**
* Mapped to call cancellation when sent by a client.
* Mapped to CANCELLED when sent by a server.
* Note that servers should only use this mechanism when they need to cancel a call but the payload byte sequence is incomplete.
*/
CANCEL(8)

知道了是由于被cancel才导致的丢包,那么就要查找为什么会被cancel,由于grpc的stub调用是通过异步的线性执行器执行io.grpc.ClientCall。所以堆栈中无法看到整个调用过程,只能通过源码来看。不管是哪种stub的调用,最后都会走到ClientCalls.startCall()方法中,然后进ClientCallImpl.start()中,在这个方法中,可以看到与cancel有关的代码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
if (context.isCancelled()) {
// Context is already cancelled so no need to create a real stream, just notify the observer
// of cancellation via callback on the executor
stream = NoopClientStream.INSTANCE;
class ClosedByContext extends ContextRunnable {
ClosedByContext() {
super(context);
}
@Override
public void runInContext() {
closeObserver(observer, statusFromCancelled(context), new Metadata());
}
}
callExecutor.execute(new ClosedByContext());
return;
}

可以看出来cancel的原因是由于context.isCancelled()的结果为true

1
2
3
4
5
6
7
public boolean isCancelled() {
if (parent == null || !cascadesCancellation) {
return false;
} else {
return parent.isCancelled();
}
}

可以看出,如果parent==null,则不可能为true,所以必然是由于parent.isCancelled()为true导致的。由此我们基本可以猜测出来,当前的ClientCall被cancel的原因是由于它的parent context canceled导致。

回到ClientCallImpl中,可以看到this.context = Context.current();表明每个ClientCall被创建的时候,context都会被赋值为Context.current()

1
2
3
4
5
6
7
public static Context current() {
Context current = storage().current();
if (current == null) {
return ROOT;
}
return current;
}

如果当前没有context,则用ROOT作为context

1
2
3
4
5
6
7
8
/**
* The logical root context which is the ultimate ancestor of all contexts. This context
* is not cancellable and so will not cascade cancellation or retain listeners.
*
* Never assume this is the default context for new threads, because {@link Storage} may define
* a default context that is different from ROOT.
*/
public static final Context ROOT = new Context(null);

在注释中可以看出,ROOT是不可以被cancel的,所以可以判断,当前必然有一个grpc的context存在。

最后联想到由于业务代码中,ClientCall是在ServerA处理grpc请求的过程中执行的,那么这个Context必然是由GrpcServer处理请求的时候生成的,并赋值给了ClientCall。而由于ClientCall是线性执行器中异步执行,当真正执行ContextRunnable的时候,GrpcServer的context可能已经被cancel,导致当前ClientCall被cancel。

解决办法:可以对当前context进行fork,或者把每个call都封装为Runnable,通过Context提供的run静态方法执行。

至此,终于弄清楚了grpc丢包的原因。虽然,这个问题通过业务层代码可以避免掉,但是我觉得grpc在底层默默的把这件事做了,并且没有往上层抛出任何信息,这对开发者是非常不友好的。同时,这个cancel逻辑的处理上,我觉得也有待商榷。毕竟在GrpcServer中异步的去执行GrpcCall是一个非常普遍合理的模型。也许以后Google会改吧。