SOFA-ARK-telnet-server-worker-0-T1”的线程CPU持续占用率100%

pk604437000 commented 5 years ago

我们在使用SofaBoot时，已经发生了两次线程跑飞，CPU持续使用率100%的情况，并且都是发生在“SOFA-ARK-telnet-server-worker-0-T1”的线程中，以下是我们使用JStack抓取到的此现成的状况，询问一下解决办法。

"SOFA-ARK-telnet-server-worker-0-T1" #10 daemon prio=5 os_prio=0 tid=0x00007f930cfb3000 nid=0x24e9 runnable [0x00007f92e66f4000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)

locked <0x00000000c456de38> (a sun.nio.ch.Util$3)
locked <0x00000000c456de28> (a java.util.Collections$UnmodifiableSet)
locked <0x00000000c456dc90> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at com.alipay.sofa.ark.container.session.StandardTelnetServerImpl$1.run(StandardTelnetServerImpl.java:118) 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)

Locked ownable synchronizers:
<0x00000000c456e378> (a java.util.concurrent.ThreadPoolExecutor$Worker)

如有发现解决办法与预防措施，请您发送邮件至以下邮箱中。 yizhenfeng@lionsway.cn

pk604437000 commented 5 years ago

sofabot version：

com.alipay.sofa sofaboot-dependencies 3.1.0

QilongZhang commented 5 years ago

反馈的堆栈看起来没什么问题，当这个线程 CPU 使用率 100% 时，有dump那个时候的线程栈吗？

khotyn commented 5 years ago

@pk604437000 后面出现的时候可以用 https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads 这个工具把当时 CPU 占用较高的 Java 线程给抓出来看看。

QilongZhang commented 5 years ago

@pk604437000 @khotyn 谷歌了下，有不少人反馈类似的问题堆栈，应该是 NIO 官方的 BUG，说是在 JDK7 修复，也有人反馈在 JDK7 也存在类似的问题，只是概率比较低. https://github.com/netty/netty/issues/327 https://bugs.java.com/bugdatabase/view_bug.do?bug_id=6403933 https://github.com/Yhzhtk/note/issues/26

QilongZhang commented 5 years ago

你们机器 JDK 版本多少？

pk604437000 commented 5 years ago

你们机器 JDK 版本多少？

我们用的JDK8

pk604437000 commented 5 years ago

你们机器 JDK 版本多少？

请问这个问题是在什么情况下会发生？我们尽量避免这种情况，或者在出现这种情况下，如何进行无损恢复。

QilongZhang commented 5 years ago

结合网上的讨论，内部聊了下，认为是 JDK NIO 的 Bug，计划在 1.0.0 版本使用 netty 替代。

如果你们不使用 telnet，暂时可以通过系统参数 -Dsofa.ark.telnet.server.enable=false 禁止 telnet 服务端启动，推荐你们使用 0.6.0 版本 API 的替代 telnet 的方式

pk604437000 commented 5 years ago

结合网上的讨论，内部聊了下，认为是 JDK NIO 的 Bug，计划在 1.0.0 版本使用 netty 替代。

如果你们不使用 telnet，暂时可以通过系统参数 -Dsofa.ark.telnet.server.enable=false 禁止 telnet 服务端启动，推荐你们使用 0.6.0 版本 API 的替代 telnet 的方式

请问是使用zookeeper去管理配置ark-biz包那个官方文档吗？如果不是请问0.6.0版本的API文档在哪里？

QilongZhang commented 5 years ago

文档可以参考：

上面是使用 ZK 和 ArkClient API 的文档， API 相对会更简单，可以参考上面两篇文档。

QilongZhang commented 5 years ago

在 alipay/sofa-ark#229 跟进

nickChenyx commented 5 years ago

结合网上的讨论，内部聊了下，认为是 JDK NIO 的 Bug，计划在 1.0.0 版本使用 netty 替代。

如果你们不使用 telnet，暂时可以通过系统参数 -Dsofa.ark.telnet.server.enable=false 禁止 telnet 服务端启动，推荐你们使用 0.6.0 版本 API 的替代 telnet 的方式

@QilongZhang 确定是 JDK NIO 的 Bug 吗？我的应用也出现了类似的问题 -> epollWait 占用了较高的 cpu 另服务器 load 偏高。我看了 https://github.com/netty/netty/issues/327 这里的讨论（实际上也是最后的 issue 关联才让我跳转到这里）

我看了调用堆栈，可以看到实际上就是 Netty 的 NioEventLoop 类中使用了 sun.nio.ch.SelectorImpl 作为实现，我查了下 Java NIO 的 selector 实现，最后也是走到这个类。所以感觉这个问题切换到 Netty 应该也存在吧？困惑于此，烦请解答下

"nioEventLoopGroup-6-3" Id=69 cpuUsage=21% RUNNABLE (in native)
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    -  locked io.netty.channel.nio.SelectedSelectionKeySet@3c7070f1
    -  locked java.util.Collections$UnmodifiableSet@1088f066
    -  locked sun.nio.ch.EPollSelectorImpl@1d2bf1aa
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:731)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:391)
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:873)
    at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)
    at java.lang.Thread.run(Thread.java:748)

这里可以看到 NioEventLoop 也去找了 sun.nio.ch.SelectorImpl

private Selector openSelector() {
        final AbstractSelector selector;
        try {
            selector = this.provider.openSelector();
        } //...

        if (DISABLE_KEYSET_OPTIMIZATION) {
            return selector;
        } else {
       //...
                public Object run() {
                    try {
                        return Class.forName("sun.nio.ch.SelectorImpl", false, PlatformDependent.getSystemClassLoader());
                    } //...
                }
            });

chpengzh commented 5 years ago

@nickChenyx

jdk这个问题是Selector.select() return 0导致空转产生的，netty是在select的时候统计了返回值，如果连续返回超过一定次数，就会对selector进行重建，可以参考netty

nickChenyx commented 4 years ago

@nickChenyx

jdk这个问题是Selector.select() return 0导致空转产生的，netty是在select的时候统计了返回值，如果连续返回超过一定次数，就会对selector进行重建，可以参考netty

昨天就看到你的回复了，十分感谢。今天早上才发现你并不是我艾特询问的那个人。= =再次感谢。此处代码中的实现是 EpollEventLoop 另看 netty 的代码仓库，发现 epoll_wait0 方法也在 4.1 版本发生了改写，native 实现直接就是设置 epoll_wait 的 timeout 为 -1 了，这里会升级一下 netty 看下运行结果。另结合我目前的线上运行状况，问题还没有挖掘清楚，还在继续排查其他可能

sofastack / sofa-boot

SOFA-ARK-telnet-server-worker-0-T1”的线程CPU持续占用率100% #382