Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Dubbo-6567] fix consumer warning "safe guard client , should not be called ,must have a bug." #6959

Closed

Conversation

wikiwikiwiki
Copy link

@wikiwikiwiki wikiwikiwiki commented Nov 30, 2020

issue #6567 里面提到了这个问题,刚好也碰到了,修复一下。

具体触发条件为:

  1. 启动一个普通consumer和一个provider,consumer可以正常调用。
  2. 关闭provider进程,观察注册中心,一直等到provider注册的url消失。
  3. 重启provider进程,consumer再次调用,报"safe guard client , should not be called ,must have a bug."并且之后每5000次调用会触发一次。

这个问题的根源是LazyConnectExchangeClient在两种情况下被使用,这两种情况需要表现的行为不一样,但是代码一样导致。
这两种情况一个是consumer主动设置为延迟连接,一个是consumer和provider断开连接时进行防御式编程,如果在连接关闭后还有请求过来就用这个延迟初始化的client处理一下。

具体到上面的这个例子:
第一步consumer正常调用时,DubboProtocol里面referenceClientMap字段保存了consumer连接provider的ReferenceCountExchangeClient。
第二步关闭provider进程一直到provider注册url消失时,referenceClientMap字段里面的引用还在,但是ReferenceCountExchangeClient的replaceWithLazyClient方法被调用,内部的ExchangeClient换成了LazyConnectExchangeClient。
第三步provider进程重启,consumer再次调用时,会重新获取到这个已经关闭的ReferenceCountExchangeClient。判断代码为

referenceCountExchangeClient == null || referenceCountExchangeClient.isClosed()

而referenceCountExchangeClient.isClosed()会调用到LazyConnectExchangeClient的isClosed方法

if (client != null) {
    return client.isClosed();
} else {
    return false;
}

此时还没有延迟初始化,会直接返回false,导致后续的调用都会使用这个client,每5000报告一次warning。

这个bug应该是在 #5532 这个pr被合并后触发,原本LazyConnectExchangeClient在没有client时isClosed()方法会返回true,会在上面例子第三步时给清理掉。而在没有client时,isClosed()方法返回false,应该是针对consumer主动设置为延迟连接的情况;而consumer和provider断开连接时建立的那个LazyConnectExchangeClient的isClosed()方法应该始终返回true。

具体修复方式为模仿replaceWithLazyClient方法里的方式,在场景不同时添加参数。
通过增加一个LAZY_CLOSE_STATE_KEY,强制设置isClosed方法修改的返回值,isClosed()方法内容改为

        if (closeState != null) {
            return closeState;
        }

        if (client == null) {
            return false;
        } else {
            return client.isClosed();
        }

@wow-blacksheep
Copy link

你好,请问我在不升级dubbo的情况下,有没有好的方式解决这个问题

@wikiwikiwiki
Copy link
Author

你好,请问我在不升级dubbo的情况下,有没有好的方式解决这个问题

好的方式只有改代码发一遍替换jar包

@AlbumenJ
Copy link
Member

@wikiwikiwiki Hi, thanks for your contribution.

Please merge the latest master branch to resolve confilcts.

@AlbumenJ AlbumenJ added the status/waiting-for-feedback Need reporters to triage label Apr 12, 2021
# Conflicts:
#	dubbo-rpc/dubbo-rpc-dubbo/src/main/java/org/apache/dubbo/rpc/protocol/dubbo/LazyConnectExchangeClient.java
#	dubbo-rpc/dubbo-rpc-dubbo/src/main/java/org/apache/dubbo/rpc/protocol/dubbo/ReferenceCountExchangeClient.java
@wikiwikiwiki
Copy link
Author

@wikiwikiwiki Hi, thanks for your contribution.

Please merge the latest master branch to resolve confilcts.

already resolved

@AlbumenJ
Copy link
Member

image

pls fix ut

@xiaoheng1
Copy link
Contributor

relation to #7737.

@AlbumenJ
Copy link
Member

Related with @7737

Please feel free to reopen if you have any question.

@startjava
Copy link

@AlbumenJ 什么时候放出FIX这个BUG的新版本?

@startjava
Copy link

另外顺便问一下,现在阿里官方是不是没有人维护DUBBO了,感觉解决问题的都是热心网友,官方不再参与了,是一个弃儿。

@AlbumenJ
Copy link
Member

AlbumenJ commented Jun 3, 2021

@AlbumenJ 什么时候放出FIX这个BUG的新版本?

本月会发 2.7.12 版本

@sh1yu
Copy link
Contributor

sh1yu commented Jun 16, 2021

@AlbumenJ 什么时候放出FIX这个BUG的新版本?

本月会发 2.7.12 版本

2.7.12版本已经发布,但是release log上并无该问题的修复说明。请问该问题已经修复了吗?

@AlbumenJ
Copy link
Member

@AlbumenJ 什么时候放出FIX这个BUG的新版本?

本月会发 2.7.12 版本

2.7.12版本已经发布,但是release log上并无该问题的修复说明。请问该问题已经修复了吗?

image

@masquee
Copy link

masquee commented Jul 8, 2021

safe guard client , should not be called ,must have a bug.

这个英文有点水平...

@chickenlj chickenlj added this to the 2.6.11 milestone Jul 14, 2021
@chickenlj chickenlj reopened this Jul 14, 2021
private volatile ExchangeClient client;
private AtomicLong warningcount = new AtomicLong(0);

public LazyConnectExchangeClient(URL url, ExchangeHandler requestHandler) {
// lazy connect, need set send.reconnect = true, to avoid channel bad status.
this.url = url.addParameter(SEND_RECONNECT_KEY, Boolean.TRUE.toString());
this.requestHandler = requestHandler;
this.initialState = url.getParameter(LAZY_CONNECT_INITIAL_STATE_KEY, DEFAULT_LAZY_CONNECT_INITIAL_STATE);
this.initialConnectState = url.getParameter(LAZY_CONNECT_INITIAL_STATE_KEY, DEFAULT_LAZY_CONNECT_INITIAL_STATE);
if (url.hasParameter(LAZY_CLOSE_STATE_KEY)) {

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this.closeState = null; if (url.hasParameter(LAZY_CLOSE_STATE_KEY)) { this.closeState = Boolean.parseBoolean(url.getParameter(LAZY_CLOSE_STATE_KEY)); }

return closeState;
}

if (client == null) {

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

return client == null ? false : client.isClosed();

@YsoulM
Copy link

YsoulM commented Sep 7, 2021

是不是在3.0.*版本中依旧存在这个问题的?3.0.*中没有找到这次修复提交的代码T_T

@xiaoheng1 xiaoheng1 modified the milestones: 2.6.11, 2.6.12 Sep 22, 2021
@coder-michaelwu
Copy link

coder-michaelwu commented Oct 4, 2021

今天在dubbo 2.7.8 spring-cloud-starter-dubbo:2.2.6.RELEASE 也遇见这个问题,不过貌似除了打印出该日志,并没有其他影响,仅在此评论,留作记录。

2021-10-04 20:25:49.943  WARN 46224 --- [nio-8888-exec-8] o.a.d.r.p.d.LazyConnectExchangeClient    : safe guard client , should not be called ,must have a bug.

java.lang.IllegalStateException: safe guard client , should not be called ,must have a bug.
	at org.apache.dubbo.rpc.protocol.dubbo.LazyConnectExchangeClient.warning(LazyConnectExchangeClient.java:138) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.dubbo.LazyConnectExchangeClient.request(LazyConnectExchangeClient.java:127) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.dubbo.ReferenceCountExchangeClient.request(ReferenceCountExchangeClient.java:91) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.dubbo.DubboInvoker.doInvoke(DubboInvoker.java:105) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.AbstractInvoker.invoke(AbstractInvoker.java:163) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.AsyncToSyncInvoker.invoke(AsyncToSyncInvoker.java:52) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:78) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:89) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:83) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:51) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:83) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:69) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:83) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:56) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:82) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.cluster.support.AbstractClusterInvoker.invoke(AbstractClusterInvoker.java:260) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.cluster.interceptor.ClusterInterceptor.intercept(ClusterInterceptor.java:47) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.cluster.support.wrapper.AbstractCluster$InterceptorInvokerNode.invoke(AbstractCluster.java:92) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.cluster.support.wrapper.MockClusterInvoker.invoke(MockClusterInvoker.java:88) [dubbo-2.7.8.jar:2.7.8]
	at org.apache.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:74) [dubbo-2.7.8.jar:2.7.8]

	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_231]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_231]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_231]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_231]
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:878) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:792) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:626) [tomcat-embed-core-9.0.46.jar:4.0.FR]
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) [spring-webmvc-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) [tomcat-embed-core-9.0.46.jar:4.0.FR]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) [tomcat-embed-websocket-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) [spring-web-5.2.15.RELEASE.jar:5.2.15.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1707) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_231]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_231]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.46.jar:9.0.46]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_231]

@CrazyHZM
Copy link
Member

CrazyHZM commented Oct 9, 2021

Try it with the latest version.

@CrazyHZM CrazyHZM closed this Oct 9, 2021
@eoc2015
Copy link

eoc2015 commented Oct 13, 2022

2.7.8 DubboX中复现。。。想知道2.7.8dubboX直接升到2.7.18有什么改动和不兼容吗

@AlbumenJ
Copy link
Member

2.7.8 DubboX中复现。。。想知道2.7.8dubboX直接升到2.7.18有什么改动和不兼容吗

dubbox 版本是基于 apache/dubbo 2.5.x 的版本,从 dubbox 升级到 dubbo 2.7 参考 dubbo 2.7 升级的文档
https://dubbo.apache.org/zh/docsv2.7/user/versions/version-270/

@echojun186
Copy link

mark

@OnlyTL
Copy link

OnlyTL commented Feb 22, 2023

一定有bug

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status/waiting-for-feedback Need reporters to triage
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet