问题描述

产品线反馈RocketMQ某Group ID出现消息堆积，重启后正常，一段时间后再次堆积，近期堆积问题出现的频次有些高，希望能够分析解决下。

分析过程

通过以往消息堆积的案例经验：

● MQ-消息堆积-业务代码异常导致retry队列积压

● MQ-消息堆积-业务线程阻塞案例分析

● 一次RocketMQ ons SDK Bug导致消息不断堆积到重试队列的案例分析

● MQ-消息堆积-JDK Bug导致线程阻塞案例分析

相比RocketMQ和JDK bug，应用代码出现问题的概率更高一些，所以优先从业务层面排查：

● 业务代码抛出了异常导致retry队列堆积，通过【详细信息】没有发现消费失败的情况，所以排除这种情况；

● 业务线程消费慢？或者是卡死了？

线程阻塞？

根据以往经验的总结，分析线程阻塞通常有如下几种思路：

● 根据线程CPU使用率（线程阻塞的情况下，CPU使用率通常很低）

● 通过对RocketMQ Listener执行耗时进行监控：一种检测线程阻塞的实现思路

● 通过对线程池线程执行时间进行监控（不做详细描述）

监控runWorker的退出时间

监控beforeExecute(wt, task)开始执行时间

监控afterExecute(task, thrown)开始执行时间

● 卡死线程的线程栈是不变得，可以通过不断查看线程栈进行分析

在没有任何系统建设的情况下，通过不断查看线程栈是可操作性最高的，下面是堆栈信息：

将【堆栈信息】中的线程浏览了一下，发现非常多的线程都处于上面线程的状态，相比较线程消费慢，现在更倾向于线程卡死了。

接下来分析上图中tid=354457的线程，为了方便分析线程栈，可以使用arthas thread命令，通过不断执行thread 354457来观察线程栈的变化：

通过不断执行，线程都保持上图状态，可以确定线程卡死了。

通过以上线程栈可知，业务代码使用apache httpclient框架发起的SSL请求，在SSL握手的时候发生了阻塞，接下来分析具体阻塞在SSL握手的哪个阶段。

SSL握手

在具体分析SSL握手阻塞在哪个阶段之前，我们先了解下SSL握手过程，以便更好理解代码的实现逻辑。

握手概述

TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256说明

TLS 是双方通信的协议；
ECDHE和 RSA都是非对称加密算法，用于传递秘钥；ECDHE 是秘钥交换算法，RSA 是签名算法；
WITH是连接字符串；
AES-128-GCM 是对称加密算法，也就是后面双方交换应用信息时使用的算法；
SHA256是消息摘要算法

TLS协议

RSA握手过程

代码分析

业务代码

根据线程栈，使用arthas jad反编译代码，相关代码整理后如下：

SSLSocket握手

SSL握手主要流程：创建Socket、socket建立与服务端连接、SSL握手，主要代码整理如下：

由于【创建Socket】和【socket建立于服务端连接】与问题关联不大，下面主要分析创建SSLSocket和建立SSL握手的过程。

创建SSLSocket

SSLSocketFactoryImpl

public Socket createSocket(Socket s, String host, int port,
                           boolean autoClose) throws IOException {
    return new SSLSocketImpl(context, s, host, port, autoClose);
}

SSLSocketImpl

SSLSocketImpl(SSLContextImpl context, Socket sock, String host,
              int port, boolean autoClose) throws IOException {
    super(sock);
    // We always layer over a connected socket
    if (!sock.isConnected()) {
        throw new SocketException("Underlying socket is not connected");
    }
    this.host = host;
    this.serverNames =
        Utilities.addToSNIServerNameList(this.serverNames, this.host);
    init(context, false);
    this.autoClose = autoClose;
    doneConnect();
}

init

private void init(SSLContextImpl context, boolean isServer) {
    sslContext = context;
    sess = SSLSessionImpl.nullSession;
    handshakeSession = null;
    /*
    * role is as specified, state is START until after
    * the low level connection's established.
    */
    roleIsServer = isServer;
    connectionState = cs_START;
    ... ...
    enabledCipherSuites =
        sslContext.getDefaultCipherSuiteList(roleIsServer);
    enabledProtocols =
        sslContext.getDefaultProtocolList(roleIsServer);
    ... ...
    input = new AppInputStream(this);
    output = new AppOutputStream(this);
}

doneConnect

void doneConnect() throws IOException {
    /*
    * Save the input and output streams.  May be done only after
    * java.net actually connects using the socket "self", else
    * we get some pretty bizarre failure modes.
    */
    sockInput = super.getInputStream();
    sockOutput = super.getOutputStream();
    /*
    * Move to handshaking state, with pending session initialized
    * to defaults and the appropriate kind of handshaker set up.
    */
    initHandshaker();
}
private void initHandshaker() {
    ... ...
    // state is either cs_START or cs_DATA
    if (connectionState == cs_START) {
        connectionState = cs_HANDSHAKE;
    } else { // cs_DATA
        connectionState = cs_RENEGOTIATE;
    }
    ......
    handshaker = new ClientHandshaker(this, sslContext,
                                      enabledProtocols,
                                      protocolVersion, connectionState == cs_HANDSHAKE,
                                      secureRenegotiation, clientVerifyData, serverVerifyData);
    handshaker.setSNIServerNames(serverNames);
    handshaker.setEnabledCipherSuites(enabledCipherSuites);
    handshaker.setEnableSessionCreation(enableSessionCreation);
}

startHandshake：建立SSL握手

startHandshake调用performInitialHandshake，主要逻辑如下：

private void performInitialHandshake() throws IOException {
    synchronized (handshakeLock) {
        if (getConnectionState() == cs_HANDSHAKE) {
            kickstartHandshake();
            ... ...
            readRecord(inrec, false);
            inrec = null;
        }
    }
}

kickstartHandshake

发送ClientHello

private synchronized void kickstartHandshake() throws IOException {
    ... ...
    handshaker.activate(null);
    // 发送ClientHello
    handshaker.kickstart();
}

readRecord

private void readRecord(InputRecord r, boolean needAppData)throws IOException {
    int state;
    synchronized (readLock) {
        while (((state = getConnectionState()) != cs_CLOSED) &&
               (state != cs_ERROR) && (state != cs_APP_CLOSED)) {
            try {
                // 读取服务端响应
                r.setAppDataValid(false);
                r.read(sockInput, sockOutput);
            } catch (SSLProtocolException e) {
                ... ...
            } catch (EOFException eof) {
                ... ...
            }
            try {
                //解析响应报文
                r.decrypt(readAuthenticator, readCipher);
            } catch (BadPaddingException e) {
                ... ...
            }
            synchronized (this) {
                switch (r.contentType()) {
                    case Record.ct_handshake:
                        ... ...
                        handshaker.process_record(r, expectingFinished);
                        expectingFinished = false;
                        if (handshaker.invalidated) {
                            handshaker = null;
                            receivedCCS = false;
                            if (connectionState == cs_RENEGOTIATE) {
                                connectionState = cs_DATA;
                            }
                        } else if (handshaker.isDone()) {
                            secureRenegotiation =
                                handshaker.isSecureRenegotiation();
                            clientVerifyData = handshaker.getClientVerifyData();
                            serverVerifyData = handshaker.getServerVerifyData();
                            sess = handshaker.getSession();
                            handshakeSession = null;
                            handshaker = null;
                            connectionState = cs_DATA;
                            receivedCCS = false;
                            if (handshakeListeners != null) {
                                HandshakeCompletedEvent event =
                                    new HandshakeCompletedEvent(this, sess);
                                Thread t = new NotifyHandshakeThread(
                                    handshakeListeners.entrySet(), event);
                                t.start();
                            }
                        }
                        if (needAppData || connectionState != cs_DATA) {
                            continue;
                        }
                        break;
                    case Record.ct_application_data:
                        ... ...
                        break;
                    case Record.ct_alert:
                        recvAlert(r);
                        continue;
                    case Record.ct_change_cipher_spec:
                        ... ...
                        continue;
                    default:
                        ... ...
                        continue;
                }
                if (connectionState < cs_ERROR) {
                    checkSequenceNumber(readAuthenticator, r.contentType());
                }
                return;
            }
        }
        r.close();
        return;
    }
}

分析结论

通过线程栈及源码分析：SSLSocket已经将ClientHello发送给服务端，当前正阻塞在读取服务端响应，由于设置的socketTimeout没有起作用，在服务端一直没有响应的情况下，线程一直阻塞在读取服务端响应。

结论验证

验证的方式主要想到了以下几种

方式一问题复现

通过curl模拟请求进行了问题复现

方式二 tcpdump抓包

通过分析tcpdump报文进行验证（未实施）

方式三打开SSL debug

借助arthas在不重启应用的情况下，动态打开了SSL debug日志，方式如下：

Debug

//将sun.security.ssl.Debug静态属性设置为all
ognl '#cls=@Class@forName("sun.security.ssl.Debug"),#field=#cls.getDeclaredField("args"),#field.setAccessible(true),#field.set(#cls,"all")'
//判断设置是否生效
ognl '@sun.security.ssl.Debug@isOn("handshake")'

ClientHandshaker

//查看debug属性定义信息
ognl '#cls=@Class@forName("sun.security.ssl.Handshaker"),#field=#cls.getDeclaredField("debug"),{#field}'
//查看debug属性
ognl '@sun.security.ssl.Handshaker@debug'
//设置isReadOnly
options strict false
ognl '#cls=@Class@forName("sun.security.ssl.Handshaker"),#field=#cls.getDeclaredField("debug"),#override=#field.overrideFieldAccessor,#override.isReadOnly=false'
//设置debug属性
ognl '#deg=@sun.security.ssl.Debug@getInstance("ssl"),#cls=@Class@forName("sun.security.ssl.Handshaker"),#field=#cls.getDeclaredField("debug"),#modifiers=#field.getClass().getDeclaredField("modifiers"),#modifiers.setAccessible(true),#modifiers.setInt(#field,#field.getModifiers() & ~@java.lang.reflect.Modifier@FINAL),#field.setAccessible(true),#field.set(#cls,#deg)'

SSLSocketImpl

//设置isReadOnly
options strict false
ognl '#cls=@Class@forName("sun.security.ssl.SSLSocketImpl"),#field=#cls.getDeclaredField("debug"),#override=#field.overrideFieldAccessor,#override.isReadOnly=false'
//设置debug属性
ognl '#deg=@sun.security.ssl.Debug@getInstance("ssl"),#cls=@Class@forName("sun.security.ssl.SSLSocketImpl"),#field=#cls.getDeclaredField("debug"),#modifiers=#field.getClass().getDeclaredField("modifiers"),#modifiers.setAccessible(true),#modifiers.setInt(#field,#field.getModifiers() & ~@java.lang.reflect.Modifier@FINAL),#field.setAccessible(true),#field.set(#cls,#deg)'
//查看debug属性
ognl '@sun.security.ssl.SSLSocketImpl@debug'

InputRecord

//设置isReadOnly
options strict false
ognl '#cls=@Class@forName("sun.security.ssl.InputRecord"),#field=#cls.getDeclaredField("debug"),#override=#field.overrideFieldAccessor,#override.isReadOnly=false'
//设置debug属性
ognl '#deg=@sun.security.ssl.Debug@getInstance("ssl"),#cls=@Class@forName("sun.security.ssl.InputRecord"),#field=#cls.getDeclaredField("debug"),#modifiers=#field.getClass().getDeclaredField("modifiers"),#modifiers.setAccessible(true),#modifiers.setInt(#field,#field.getModifiers() & ~@java.lang.reflect.Modifier@FINAL),#field.setAccessible(true),#field.set(#cls,#deg)'
//查看debug属性
ognl '@sun.security.ssl.InputRecord@debug'

OutputRecord

//设置debug属性
ognl '#deg=@sun.security.ssl.Debug@getInstance("ssl"),#cls=@Class@forName("sun.security.ssl.OutputRecord"),#field=#cls.getDeclaredField("debug"),#modifiers=#field.getClass().getDeclaredField("modifiers"),#modifiers.setAccessible(true),#modifiers.setInt(#field,#field.getModifiers() & ~@java.lang.reflect.Modifier@FINAL),#field.setAccessible(true),#field.set(#cls,#deg)'
//查看debug属性
ognl '@sun.security.ssl.OutputRecord@debug'

方式四对象状态分析

通过源码分析可知：SSL握手成功的情况下，SSLSocket实例的connectionState==cs_DATA，handshaker==null；握手进行中的时候，connectionState==cs_HANDSHAKE，handshaker==ClientHandshaker。所以通过arthas vmtool分别查看对应SSLSocket实例connectionState、handshaker变量的值就可以判断处SSLSocket处于什么状态。

找出阻塞的SSLSocket

由于业务应用每次请求都创建新的SSLSocket，所以我们只要找出创建时间比较早的SSLSocket，基本都是阻塞的。

通过socket的创建时间，可以找出阻塞的socket。

SSLSocket握手完成

SSLSocket握手未完成

具体阻塞在SSLSocket握手的哪个阶段，可以通过ClientHandshaker属性值进行判断，例如：

客户端发送了ClientHello

● 当服务端响应ServerHello的时候，属性protocolVersion不为空，svr_random不为空，cipherSuite不为默认值SSL_NULL_WITH_NULL_NULL，keyExchange不为默认值K_NULL；

● 当服务端没有响应ServerHello的时候，属性protocolVersion为空，svr_random为空，cipherSuite为默认值SSL_NULL_WITH_NULL_NULL，keyExchange为默认值K_NULL。

● 当服务端响应ServerCertificate的时候，handshaker的session属性的peerCerts字段不为空；

● 当服务端没有响应ServerCertificate的时候，handshaker的session属性的peerCerts字段为空；

● 以上可以结合handshaker的state变量值进行分析

经验总结

优化HttpClient使用方式

不使用@Deprecated相关接口及实现类
HttpClient使用单例形式，而不是每个请求新建一个
SSLSessionContext参数优化，详情见：SSL Session默认设置导致线程阻塞了几十秒的案例分析

服务端为何没有响应的原因：初步判断是由于客户端频繁SSL握手，触发了服务端的安全策略（未完待续）。

SSLSocket调试

enable debug

● 方式一：JVM启动参数添加-Djavax.net.debug=all

● 方式二：通过arthas动态打开debug

handshakeListeners

通过向SSLSocket注册handshakeListeners，当SSL握手完成的时候可以获取SSL握手完成的通知。。

X509TrustManager

该类的实现类方法checkServerTrusted通常是不做实现的，不过可以在该方法中记录下SSLSocket状态信息以方便问题排查。

记一次SSL握手导致业务线程阻塞的案例分析

问题描述

分析过程

线程阻塞？

SSL握手

握手概述

TLS协议

RSA握手过程

代码分析

业务代码

SSLSocket握手

创建SSLSocket

SSLSocketFactoryImpl

SSLSocketImpl

init

doneConnect

startHandshake：建立SSL握手

kickstartHandshake

readRecord

分析结论

结论验证

方式一 问题复现

方式二 tcpdump抓包

方式三 打开SSL debug

Debug

ClientHandshaker

SSLSocketImpl

InputRecord

OutputRecord

方式四 对象状态分析

找出阻塞的SSLSocket

SSLSocket握手完成

SSLSocket握手未完成

经验总结

优化HttpClient使用方式

SSLSocket调试

enable debug

handshakeListeners

X509TrustManager

云原生

热门文章

最新文章

相关电子书

方式一问题复现

方式三打开SSL debug

方式四对象状态分析