OpenSergoClient gRPC disconnection: DEADLINE_EXCEEDED

[ruansheng8]

问题描述

部署opensergo-control-plane到K8S后 , 客户端连接成功，也成功加载了并生效了相关配置，超过Deadline限定时间(OpenSergoClient默认10S)后自动断开
Spring Boot 2.5.12，opensergo-java-sdk 0.1.0，Sentinel 2.0.0-alpha，opensergo-control-plane 基于main分支最新代码部署

问题验证

通过 sentinel-demo-opensergo-datasource 进行验证

启动客户端后连接正常（opensergo-control-plane可以看到客户端的连接的日志），且可以正确的获取到opensergo-control-plane中相关CRD配置，通过请求接口验证限流规则也正确的被加载，但是gRPC连接会自动断开，本地启动客户端或者在集群中使用域名opensergo-control-plane.opensergo-system.svc.cluster.local连接都有一样的问题。

2023-03-16 14:30:46.714 ERROR 22976 --- [ault-executor-2] openSergoLogger                          : Fatal error occurred on OpenSergo gRPC ClientObserver

io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: deadline exceeded after 9.937407200s. [closed=[], committed=[wait_for_ready, buffered_nanos=255123700, remote_addr=/192.168.4.161:10246]]

OpenSergoClient.java 中通过withDeadlineAfter来设置截止时间 , 通过手动将截止时间(withDeadlineAfter)设置为1分钟然后验证功能，期间动态修改相关CRD限流规则 , 功能一切正常(限流规则可以实时生效)，但是1分钟后客户端gRPC连接依然会被自动断开（具体见下面客户端日志）。

    public void start() throws Exception {
        this.requestAndResponseWriter = transportGrpcStub
            .withWaitForReady()
            // The deadline SHOULD be set when waitForReady is enabled
            .withDeadlineAfter(10, TimeUnit.SECONDS)
            .subscribeConfig(new OpenSergoSubscribeClientObserver(configCache, subscribeRegistry));
        // TODO: add state management for the client.
    }

其他信息

客户端日志

2023-03-16 14:30:36.763  INFO 22976 --- [           main] openSergoLogger                          : OpenSergo config subscriber registered, subscribeKey=SubscribeKey{namespace='default', app='foo-app', kind=RATE_LIMIT_STRATEGY}, subscriber=com.alibaba.csp.sentinel.datasource.OpenSergoDataSourceGroup$OpenSergoSentinelFlowRuleSubscriber@1e236278
2023-03-16 14:30:36.763  INFO 22976 --- [           main] openSergoLogger                          : OpenSergo config subscriber registered, subscribeKey=SubscribeKey{namespace='default', app='foo-app', kind=THROTTLING_STRATEGY}, subscriber=com.alibaba.csp.sentinel.datasource.OpenSergoDataSourceGroup$OpenSergoSentinelFlowRuleSubscriber@1e236278
2023-03-16 14:30:36.764  INFO 22976 --- [           main] openSergoLogger                          : OpenSergo config subscriber registered, subscribeKey=SubscribeKey{namespace='default', app='foo-app', kind=CONCURRENCY_LIMIT_STRATEGY}, subscriber=com.alibaba.csp.sentinel.datasource.OpenSergoDataSourceGroup$OpenSergoSentinelFlowRuleSubscriber@1e236278
2023-03-16 14:30:37.154  INFO 22976 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 10005 (http) with context path ''
2023-03-16 14:30:37.165  INFO 22976 --- [           main] .c.s.d.d.o.SpringWebOpenSergoApplication : Started SpringWebOpenSergoApplication in 2.729 seconds (JVM running for 3.629)
2023-03-16 14:30:46.714 ERROR 22976 --- [ault-executor-2] openSergoLogger                          : Fatal error occurred on OpenSergo gRPC ClientObserver

io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: deadline exceeded after 9.937407200s. [closed=[], committed=[wait_for_ready, buffered_nanos=255123700, remote_addr=/192.168.4.161:10246]]
	at io.grpc.Status.asRuntimeException(Status.java:535) ~[grpc-api-1.42.1.jar:1.42.1]
	at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:479) ~[grpc-stub-1.42.1.jar:1.42.1]
	at io.grpc.internal.DelayedClientCall$DelayedListener$3.run(DelayedClientCall.java:463) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.DelayedClientCall$DelayedListener.delayOrExecute(DelayedClientCall.java:427) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.DelayedClientCall$DelayedListener.onClose(DelayedClientCall.java:460) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:562) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:743) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:722) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) ~[grpc-core-1.42.1.jar:1.42.1]
	at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133) ~[grpc-core-1.42.1.jar:1.42.1]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
	at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

opensergo-control-plane日志

I0307 06:49:39.668266       1 request.go:668] Waited for 1.040117824s due to client-side throttling, not priority and fairness, request: GET:https://10.43.0.1:443/apis/catalog.cattle.io/v1?timeout=32s
{"timestamp":"2023-03-07 06:49:40.4070","caller":"deleg.go:130","logLevel":"INFO","msg":"setup Starting OpenSergo operator"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"deleg.go:130","logLevel":"INFO","msg":"setup OpenSergo CRD watcher has been registered successfully","kind":"fault-tolerance.opensergo.io/v1alpha1/FaultToleranceRule","namespace":"default","app":"foo-app"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"deleg.go:130","logLevel":"INFO","msg":"setup OpenSergo CRD watcher has been registered successfully","kind":"fault-tolerance.opensergo.io/v1alpha1/RateLimitStrategy","namespace":"default","app":"foo-app"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"deleg.go:130","logLevel":"INFO","msg":"setup OpenSergo CRD watcher has been registered successfully","kind":"fault-tolerance.opensergo.io/v1alpha1/ThrottlingStrategy","namespace":"default","app":"foo-app"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"deleg.go:130","logLevel":"INFO","msg":"setup OpenSergo CRD watcher has been registered successfully","kind":"fault-tolerance.opensergo.io/v1alpha1/ConcurrencyLimitStrategy","namespace":"default","app":"foo-app"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:165","logLevel":"INFO","msg":"controller.ratelimitstrategy Starting EventSource","source":{"Type":{"metadata":{"creationTimestamp":null},"spec":{"metricType":"","limitMode":"","threshold":0,"statDurationSeconds":0},"status":{}}},"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"RateLimitStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:165","logLevel":"INFO","msg":"controller.concurrencylimitstrategy Starting EventSource","source":{"Type":{"metadata":{"creationTimestamp":null},"spec":{"maxConcurrency":0,"limitMode":""},"status":{}}},"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"ConcurrencyLimitStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:173","logLevel":"INFO","msg":"controller.ratelimitstrategy Starting Controller","reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"RateLimitStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:173","logLevel":"INFO","msg":"controller.concurrencylimitstrategy Starting Controller","reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"ConcurrencyLimitStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:165","logLevel":"INFO","msg":"controller.throttlingstrategy Starting EventSource","source":{"Type":{"metadata":{"creationTimestamp":null},"spec":{"minIntervalOfRequests":"","queueTimeout":""},"status":{}}},"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"ThrottlingStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:173","logLevel":"INFO","msg":"controller.throttlingstrategy Starting Controller","reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"ThrottlingStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:165","logLevel":"INFO","msg":"controller.faulttolerancerule Starting EventSource","source":{"Type":{"metadata":{"creationTimestamp":null},"spec":{"targets":null,"strategies":null},"status":{}}},"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"FaultToleranceRule"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:173","logLevel":"INFO","msg":"controller.faulttolerancerule Starting Controller","reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"FaultToleranceRule"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:207","logLevel":"INFO","msg":"controller.throttlingstrategy Starting workers","worker count":1,"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"ThrottlingStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:207","logLevel":"INFO","msg":"controller.concurrencylimitstrategy Starting workers","worker count":1,"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"ConcurrencyLimitStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:207","logLevel":"INFO","msg":"controller.faulttolerancerule Starting workers","worker count":1,"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"FaultToleranceRule"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"controller.go:207","logLevel":"INFO","msg":"controller.ratelimitstrategy Starting workers","worker count":1,"reconciler group":"fault-tolerance.opensergo.io","reconciler kind":"RateLimitStrategy"}
{"timestamp":"2023-03-16 06:43:08.8160","caller":"crd_watcher.go:171","logLevel":"INFO","msg":"controller.fault-tolerance.opensergo.io/v1alpha1/RateLimitStrategy OpenSergo CRD received","crd":{"kind":"RateLimitStrategy","apiVersion":"fault-tolerance.opensergo.io/v1alpha1","metadata":{"name":"rate-limit-foo","namespace":"default","uid":"ee6fd9a4-72c0-4e1a-a28e-f3d3922416a7","resourceVersion":"87615602","generation":2,"creationTimestamp":"2023-01-11T05:55:55Z","labels":{"app":"foo-app"},"managedFields":[{"manager":"Mozilla","operation":"Update","apiVersion":"fault-tolerance.opensergo.io/v1alpha1","time":"2023-01-11T06:09:54Z","fieldsType":"FieldsV1","fieldsV1":{"f:metadata":{"f:labels":{".":{},"f:app":{}}},"f:spec":{".":{},"f:limitMode":{},"f:metricType":{},"f:statDurationSeconds":{},"f:threshold":{}}}}]},"spec":{"metricType":"RequestAmount","limitMode":"Global","threshold":1,"statDurationSeconds":5},"status":{}},"crdNamespace":"default","crdName":"rate-limit-foo","kind":"fault-tolerance.opensergo.io/v1alpha1/RateLimitStrategy"}

[ruansheng8]

Kubernetes version: v1.25.3+k3s1
Kubernetes platform: linux/amd64