背景

在一次 ZK 突然莫名的出现高负载,导致Provider、Consumer 与 ZK 连接异常,系统一直提示连接异常,但是此时对各个系统Dubbo 服务依旧正常调度,下文继续分析为什么不会影响到服务间调用。但是使得 ZK 高负载的根因是什么呢?

排查过程

日志记录异常如下:

org.apache.curator.CuratorConnectionLossException: KeeperErrorCode = ConnectionLoss
	at org.apache.curator.ConnectionState.checkTimeouts(ConnectionState.java:225)
	at org.apache.curator.ConnectionState.getZooKeeper(ConnectionState.java:94)
	at org.apache.curator.CuratorZookeeperClient.getZooKeeper(CuratorZookeeperClient.java:117)
	at org.apache.curator.framework.imps.CuratorFrameworkImpl.performBackgroundOperation(CuratorFrameworkImpl.java:835)
	at org.apache.curator.framework.imps.CuratorFrameworkImpl.backgroundOperationsLoop(CuratorFrameworkImpl.java:809)
	at org.apache.curator.framework.imps.CuratorFrameworkImpl.access$300(CuratorFrameworkImpl.java:64)
	at org.apache.curator.framework.imps.CuratorFrameworkImpl$4.call(CuratorFrameworkImpl.java:267)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

根据上面错误最终源码可知,出现的原因大致就是因为获取 ZK 链接异常所致,代码定位如下

    private synchronized void checkTimeouts() throws Exception
    {
        int minTimeout = Math.min(sessionTimeoutMs, connectionTimeoutMs);
        long elapsed = System.currentTimeMillis() - connectionStartMs;
        if ( elapsed >= minTimeout )
        {
            if ( zooKeeper.hasNewConnectionString() )
            {
                handleNewConnectionString();
            }
            else
            {
                int maxTimeout = Math.max(sessionTimeoutMs, connectionTimeoutMs);
                if ( elapsed > maxTimeout )
                {
                    if ( !Boolean.getBoolean(DebugUtils.PROPERTY_DONT_LOG_CONNECTION_ISSUES) )
                    {
                        log.warn(String.format("Connection attempt unsuccessful after %d (greater than max timeout of %d). Resetting connection and trying again with a new connection.", elapsed, maxTimeout));
                    }
                    reset();
                }
                else
                {
                    KeeperException.ConnectionLossException connectionLossException = new CuratorConnectionLossException();
                    if ( !Boolean.getBoolean(DebugUtils.PROPERTY_DONT_LOG_CONNECTION_ISSUES) )
                    {
                        log.error(String.format("Connection timed out for connection string (%s) and timeout (%d) / elapsed (%d)", zooKeeper.getConnectionString(), connectionTimeoutMs, elapsed), connectionLossException);
                    }
                    new EventTrace("connections-timed-out", tracer.get(), getSessionId()).commit();
                    throw connectionLossException;
                }
            }
        }
    }

image.png

大致原因为连接耗时大于所配置的最大连接时间,因此直接抛出异常了。

那么结合 ZK 高负载,超时异常也就能解释了。但是为什么 Provider、Consumer 已经与 ZK 断链了,为什么服务间调用依旧正常呢?

翻阅了 Dubbo 设计架构如下

image.png

Provider 将注册信息注册入 Register 后,Comsumer 订阅 Register 中的信息,随后 Dubbo 会将订阅到的 Provider 缓存到本地。因此即使 Register 宕机了,只要 Consumer 中缓存信息还在依旧能正常调用到 Provider。

OK 问题大概都清楚了剩下的就是 ZK 为什么突然高负载的问题了。此时运维同学也一直没有定位到 ZK 高负载的原因,就尝试重启了 ZK,随后一段时间恢复了,但是很快又出现上面连接异常问题。随后运维同学对 ZK 进行扩容,扩容完成后,没几个小时依旧出现了高负载问题。情况很明显了,应该是某个大杀器在疯狂吞噬 ZK 资源,不找到根因一味扩容应该是不起作用的了。

但是此时迟迟无法定位到问题,运维同学直接强制清除 ZK 缓存,此时服务间出现短暂的调用异常,但是大部分个服务很快又重新注册,Consumer 再重新去 Register 拉去最新 Provider 信息。但是部分服务还是出现问题,异常信息如下:


com.alibaba.dubbo.rpc.RpcException: Forbid consumer 172.*.*.39 access service com.xhqb.lc.decision.common.service.api.DecisionService from registry 10.*.*.3:2181 use dubbo version 2.8.4, Please check registry access list (whitelist/blacklist).
	at com.alibaba.dubbo.registry.integration.RegistryDirectory.doList(RegistryDirectory.java:579)
	at com.alibaba.dubbo.rpc.cluster.directory.AbstractDirectory.list(AbstractDirectory.java:73)
	at com.alibaba.dubbo.rpc.cluster.support.AbstractClusterInvoker.list(AbstractClusterInvoker.java:260)
	at com.alibaba.dubbo.rpc.cluster.support.AbstractClusterInvoker.invoke(AbstractClusterInvoker.java:219)
	at com.alibaba.dubbo.rpc.cluster.support.wrapper.MockClusterInvoker.invoke(MockClusterInvoker.java:72)
	at com.alibaba.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:52)
	at com.alibaba.dubbo.common.bytecode.proxy34.proessDecision(proxy34.java)

通过日志信息可知,该服务被注册中心禁止消费了。what?!发生甚麽事了。Provider 重新注册一下该服务就被禁止消费了。没办法,继续翻翻源码看看究竟发生什么事了吧

public List<Invoker<T>> doList(Invocation invocation) {
        if (forbidden) {
            throw new RpcException(RpcException.FORBIDDEN_EXCEPTION, "Forbid consumer " +  NetUtils.getLocalHost() + " access service " + getInterface().getName() + " from registry " + getUrl().getAddress() + " use dubbo version " + Version.getVersion() + ", Please check registry access list (whitelist/blacklist).");
        }
        List<Invoker<T>> invokers = null;
        Map<String, List<Invoker<T>>> localMethodInvokerMap = this.methodInvokerMap; // local reference
        if (localMethodInvokerMap != null && localMethodInvokerMap.size() > 0) {
            String methodName = RpcUtils.getMethodName(invocation);
            Object[] args = RpcUtils.getArguments(invocation);
            if(args != null && args.length > 0 && args[0] != null
                    && (args[0] instanceof String || args[0].getClass().isEnum())) {
                invokers = localMethodInvokerMap.get(methodName + "." + args[0]); // 可根据第一个参数枚举路由
            }
            if(invokers == null) {
                invokers = localMethodInvokerMap.get(methodName);
            }
            if(invokers == null) {
                invokers = localMethodInvokerMap.get(Constants.ANY_VALUE);
            }
            if(invokers == null) {
                Iterator<List<Invoker<T>>> iterator = localMethodInvokerMap.values().iterator();
                if (iterator.hasNext()) {
                    invokers = iterator.next();
                }
            }
        }
        return invokers == null ? new ArrayList<Invoker<T>>(0) : invokers;
    }

通过报错位置定位到源码,该方法获取具体的调用 Dubbo 服务 Invoker ,若 forbiden 值被设置为 true,则直接抛出异常,找到 forbiden 设值代码

    private void refreshInvoker(List<URL> invokerUrls){
        if (invokerUrls != null && invokerUrls.size() == 1 && invokerUrls.get(0) != null
                && Constants.EMPTY_PROTOCOL.equals(invokerUrls.get(0).getProtocol())) {
            this.forbidden = true; // 禁止访问
            this.methodInvokerMap = null; // 置空列表
            destroyAllInvokers(); // 关闭所有Invoker
        } else {
            this.forbidden = false; // 允许访问
            Map<String, Invoker<T>> oldUrlInvokerMap = this.urlInvokerMap; // local reference
            if (invokerUrls.size() == 0 && this.cachedInvokerUrls != null){
                invokerUrls.addAll(this.cachedInvokerUrls);
            } else {
                this.cachedInvokerUrls = new HashSet<URL>();
                this.cachedInvokerUrls.addAll(invokerUrls);//缓存invokerUrls列表,便于交叉对比
            }
            if (invokerUrls.size() ==0 ){
            	return;
            }
            Map<String, Invoker<T>> newUrlInvokerMap = toInvokers(invokerUrls) ;// 将URL列表转成Invoker列表
            Map<String, List<Invoker<T>>> newMethodInvokerMap = toMethodInvokers(newUrlInvokerMap); // 换方法名映射Invoker列表
            // state change
            //如果计算错误,则不进行处理.
            if (newUrlInvokerMap == null || newUrlInvokerMap.size() == 0 ){
                logger.error(new IllegalStateException("urls to invokers error .invokerUrls.size :"+invokerUrls.size() + ", invoker.size :0. urls :"+invokerUrls.toString()));
                return ;
            }
            this.methodInvokerMap = multiGroup ? toMergeMethodInvokerMap(newMethodInvokerMap) : newMethodInvokerMap;
            this.urlInvokerMap = newUrlInvokerMap;
            try{
                destroyUnusedInvokers(oldUrlInvokerMap,newUrlInvokerMap); // 关闭未使用的Invoker
            }catch (Exception e) {
                logger.warn("destroyUnusedInvokers error. ", e);
            }
        }
    }
  

com.alibaba.dubbo.registry.integration.RegistryDirectory#refreshInvoker 方法通常在以下情况下被调用:

  1. 服务列表发生变化时 :当服务提供者的列表发生变化时,比如新增或减少了提供者,或者某个服务提供者的地址发生变化,Dubbo 注册中心会通知订阅了该服务的消费者。此时,消费者端会触发 refreshInvoker 方法,以便更新内部维护的服务提供者列表。
  2. 注册中心下发通知时 :Dubbo 注册中心在检测到服务提供者的变化(包括上线、下线或地址变更)后,会向相关的消费者发送通知。RegistryDirectory 作为服务目录,在接收到这些通知后,会调用 refreshInvoker 方法来刷新本地的服务调用器列表。
  3. 服务重启或重连时 :当消费者服务重启或因为网络问题重新连接到注册中心时,也可能触发 refreshInvoker 方法,以确保重新获取最新的服务提供者列表。

也即 Provider 在与 ZK 重新建立连接,由于先前 ZK 缓存被清除需要将信息重新注册入 ZK,ZK 发现 Provider 存在信息变更通知到 Consumer 有信息变更,因此Consumer 服务将 forbiden 设置为了 true ,此时再有方法调用对应服务即出现了上面异常。

PS:由于上面信息提示的不准确,在新版本的 Dubbo 已经优化了该异常提示。具体可见GitHHub 上对 Dubbo 维护Issues链接:优化consumer找不到provider时的提示内容,当前提示容易误导使用者服务被禁用forbid

ZK 缓存被清理了大部分服务都是能重新注册,但是存在部分服务一直没能被注册上,而且还存在一部分服务部分请求正常,部分请求依旧是上面异常。泪崩~~~

由于当时情况紧急,我们是先对相关异常服务的机器进行了重启,随后立马服务就重新注册,并获取到了最新的服务列表恢复正常了,接下来剖析下上面出现的问题。

对于清除 ZK 后 Consumer 无法请求到 Provider,可能是 Provider 未在 Register 注册成功,查阅相关资料及源码发现如下:

	public void createEphemeral(String path) {
		try {
			client.create().withMode(CreateMode.EPHEMERAL).forPath(path);
		} catch (NodeExistsException e) {
		} catch (Exception e) {
			throw new IllegalStateException(e.getMessage(), e);
		}
	}

在 Zookeeper 中,临时节点(Ephemeral Node)的删除是和客户端会话直接相关的。当会话失效时,Zookeeper 保证该会话创建的所有临时节点都会被自动删除。但由于网络延迟或其他因素,客户端可能不会立即感知到会话失效。

当调用 createEphemeral 方法时,如果 Zookeeper 发现当前路径已经存在节点,就会抛出 NodeExistsException。在以下几种情况下可能出现这种异常:

  • 旧会话未及时失效: 假设客户端网络抖动或其他原因导致会话暂时中断,而 Zookeeper 还没有完全检测到会话失效,临时节点还未被删除。当你重新尝试注册同样的路径时,Zookeeper 会抛出 NodeExistsException
  • 并发注册: 如果有多个客户端尝试在同一时刻注册同一个路径,也可能会导致 NodeExistsException

当会话失效但节点尚未删除时,新会话尝试创建相同路径的临时节点会出现 NodeExistsException,导致服务未重新注册。特别是在高并发或网络不稳定的情况下。

总结

遇事不要慌,先观察异常状况,然后跟着源码逐步分析原因


标题:记一次 Zookeeper 高负载引发的一系列问题
作者:JonLv
地址:http://39.108.183.139:8080/articles/2024/08/09/1723172717502.html