Skip to content

OpenSergoClient gRPC disconnection: DEADLINE_EXCEEDED #29

@ruansheng8

Description

@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"}

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions