前言

工作多年，经常遇到灵异事件，比如说: "任务为什么不跑了" , "没什么复杂业务呀，怎么cpu这么高" ,"用了缓存，怎么查询还是这么慢" , 一些工作一两年的同学遇到这类问题可能会手足无措，所以我想写一些文字来和大家分享下。文笔有限，主要是交流。这篇是先和大家交流 jstack的用法，以及编程方面的一些建议。

1 经典场景

场景一：任务（线程）突然不跑了

程序是一段简单的quartz 任务，伪代码类似:

public class DataJobs {   public void run() {    log.info("任务开始运行");    //准备数据     Object prepareData = prepare();    //调用http远程接口获取    Result result = getHttpRemoteData(prepareData);    //存储    store(result);    log.info("任务结束运行");   }}

查看日志可用查看到 “任务开始运行” 但后续没有打印“任务结束运行”

业务也没有正常处理 , 也没有异常无奈之下只好重启服务

场景二 cpu load 特别高业务也不复杂

如下图:

业务场景是比分直播。

页面的逻辑是每隔几秒从memached 获取实时比赛信息，根据彩种类别获取数据，然后前端渲染。

页面访问伪代码类似:

 @RequestMapping("/getLiveData") @ResponseBody public String getLiveData(String lotteryCode) {     //从memcache中获取比分直播数据  仅仅是一个 get key from memcahed     String result = getDataFromMemcache(lotteryCode);      return result; }

异常问题：页面非常卡顿，服务器上 cpu 利用率和 load 非常高。

2 jstack分析

jstack是jdk自带的线程堆栈分析工具，使用该命令可以查看或导出 Java 应用程序中线程堆栈信息。

执行命令类似:

jstack -l pid >> statck.txt

有时也可以采用 kill -3 命令实现打印堆栈的效果

kill  -3  pid

堆栈格式：

"redisson-netty-2-4" #37 prio=5 os_prio=0 tid=0x00007f91ae738000 nid=0x3bf1 runnable [0x00007f91a5b4d000]  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 <0x00000000ee106580> (a io.netty.channel.nio.SelectedSelectionKeySet)      - locked <0x00000000ee1065b0> (a java.util.Collections$UnmodifiableSet)      - locked <0x00000000edff8448> (a sun.nio.ch.EPollSelectorImpl)      at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)      at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62)      at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:752)       at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:408)       at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)       at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)       at java.lang.Thread.run(Thread.java:748)
   Locked ownable synchronizers:        - None

dump格式说明：

属性	说明
redisson-netty-2-4	线程名称
prio=5	该线程jvm中优先级 ‍
os_prio=0	该线程在os中的优先级 ‍
tid	该jvm内的thread id ‍
nid	Native thread id 本地操作系统相关 (高度依赖操作系统平台)

‍

在jstack输出的第二行为线程的状态，在JVM中线程状态使用枚举 java.lang.Thread.State 来表示，State的定义如下：

 public enum State {        NEW,        RUNNABLE,        BLOCKED,        WAITING,        TIMED_WAITING,        TERMINATED;    }

在线程转换图：

jstack关键字分析

关键字	说明
deadlock	死锁
waiting on condition	等待某个资源或条件发生来唤醒自己。具体需要结合jstacktrace来分析，比如线程正在sleep,网络读写繁忙而等待
Blocked	阻塞
waiting on monitor entry	等待获取锁 ‍
in Object.wait()	获取锁后又执行obj.wait()

3 解决问题

3.1 线程阻塞问题

回到场景一依靠上面的命令我们打印出模拟的jstack堆栈

"Quartz-2" #1 prio=5 os_prio=31 tid=0x00007feb6c008000 nid=0x2603 runnable [0x000070000771a000]   java.lang.Thread.State: RUNNABLE  at java.net.SocketInputStream.socketRead0(Native Method)  at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)  at java.net.SocketInputStream.read(SocketInputStream.java:170)  at java.net.SocketInputStream.read(SocketInputStream.java:141)  at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)  at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)  at java.io.BufferedInputStream.read(BufferedInputStream.java:345)  - locked <0x00000007959e1830> (a java.io.BufferedInputStream)  at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:704)  at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:647)  at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1535)  - locked <0x00000007959b1848> (a sun.net.www.protocol.http.HttpURLConnection)  at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1440)  - locked <0x00000007959b1848> (a sun.net.www.protocol.http.HttpURLConnection)  at sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:2942)  at java.net.URLConnection.getContentType(URLConnection.java:512)  at com.courage.platform.sms.client.util.SmsHttpClientUtils.getResponseAsString(SmsHttpClientUtils.java:345)  at com.courage.platform.sms.client.util.SmsHttpClientUtils.doGet(SmsHttpClientUtils.java:241)

由上可见，当前线程阻塞在从http链接中获取响应数据。可能对方httpserver耗时长，或者对方server hang住了。针对这种情况，我适当的调整了 http client 的 connect 和read timeout。

3.2 cpu高问题

回到场景二，

我们先用ps命令找到对应进程的pid(如果你有好几个目标进程，可以先用top看一下哪个占用比较高)。
接着用

top -H -p pid

来找到cpu使用率比较高的一些线程（下图是模拟图）

然后将占用最高的pid转换为16进制printf '%x\n' pid得到nid

接着直接在jstack中找到相应的堆栈信息jstack pid | grep 'nid' -C5 –color

可以看到我们已经找到了nid为0x42的堆栈信息。

比分直播我们查询到占用cpu最高的是 GC 线程。那我们怀疑是由于GC 频率过高导致的。

然后使用 jstat 每隔1s查看内存使用情况

jstat -gcutil pid 1000

发现新生代每隔两秒就基本占满了 , 然后查看每个key对应的数据大小，发现每个value大小是500k左右。

解决方式也比较简单 :

减少缓存数据大小
适当调整新生代的大小
首次查询全量，后续通过websocket推送增量给前端

4 编码习惯引导

4.1 设置线程名

线程名设置主要是为了在jstack堆栈中便于查询。在logback日志中最好也标注下线程名。当遇到问题也有一个查询源。

线程名有如下两种方式:

手工设置线程名

Thread t = new Thread(new Runnable() {     @Override     public void run() {       //something process       }});t.setName("mytestThread");t.start();

线程工厂设置（源码来自rocketmq 4.4）

public class ThreadFactoryImpl implements ThreadFactory {    private final AtomicLong threadIndex = new AtomicLong(0);    private final String threadNamePrefix;    private final boolean daemon;    public ThreadFactoryImpl(final String threadNamePrefix) {      this(threadNamePrefix, false);    }    public ThreadFactoryImpl(final String threadNamePrefix, boolean daemon) {      this.threadNamePrefix = threadNamePrefix;      this.daemon = daemon;    }    @Override    public Thread newThread(Runnable r) {     Thread thread = new Thread(r, threadNamePrefix + this.threadIndex.incrementAndGet());      thread.setDaemon(daemon);      return thread;    }}

使用方式：

this.traceExecutor = new ThreadPoolExecutor(  10,   20,   1000 * 60,   TimeUnit.MILLISECONDS,   this.appenderQueue,  new ThreadFactoryImpl("MQTraceSendThread_"));traceProducer = getAndCreateTraceProducer(rpcHook);

4.2 线程池隔离

线程隔离主要有线程池隔离，在实际使用时我们会把请求分类，然后交给不同的线程池处理，当一种业务的请求处理发生问题时，不会将故障扩散到其他线程池，从而保证其他服务可用。

以开源代码rocketmq举例:

我们来看下broker启动时，发送消息 & pull 消息都是不同的线程池处理请求。

分为

发送消息线程池
pull消息线程池
查询消息线程池
回复消息线程池

代码如下:

//发送消息 处理器this.remotingServer.registerProcessor(RequestCode.SEND_MESSAGE, sendProcessor, this.sendMessageExecutor);
//pull消息 处理器this.remotingServer.registerProcessor(RequestCode.PULL_MESSAGE, this.pullMessageProcessor, this.pullMessageExecutor);this.pullMessageProcessor.registerConsumeMessageHook(consumeMessageHookList);
//消费管理处理器ConsumerManageProcessor consumerManageProcessor = new ConsumerManageProcessor(this);this.remotingServer.registerProcessor(RequestCode.GET_CONSUMER_LIST_BY_GROUP, consumerManageProcessor, this.consumerManageExecutor);
//事务处理器this.remotingServer.registerProcessor(RequestCode.END_TRANSACTION, new EndTransactionProcessor(this), this.endTransactionExecutor);this.fastRemotingServer.registerProcessor(RequestCode.END_TRANSACTION, new EndTransactionProcessor(this), this.endTransactionExecutor);

4.3 超时设置

为了避免线程池大规模阻塞，合理的设置超时时间非常重要。常见超时有如下

http 读写超时（jdk httpurlconnection）

cononnection(new URL(n = getCurl), METHOD_POST, ctype);fillHeaders(conn, headers);conn.setConnectTimeout(connectTimeout);conn.setReadTimeout(readTimeout);out = conn.getOutputStream();

加锁时间(分布式场景下 redission)

RLock lock = redisson.getLock("myLock");// traditional lock methodlock.lock();// or acquire lock and automatically unlock it after 10 secondslock.lock(10, TimeUnit.SECONDS);// or wait for lock aquisition up to 100 seconds // and automatically unlock it after 10 secondsboolean res = lock.tryLock(100, 10, TimeUnit.SECONDS);if (res) {   try {     ...   } finally {       lock.unlock();   }}

网络通讯（通过countdownlatch实现）

 public RemotingCommand invokeSyncImpl(final Channel channel, final RemotingCommand request,        final long timeoutMillis)   throws InterruptedException, RemotingSendRequestException, RemotingTimeoutException {    final int opaque = request.getOpaque();    try {       final ResponseFuture responseFuture = new ResponseFuture(channel, opaque, timeoutMillis, null, null);       this.responseTable.put(opaque, responseFuture);       final SocketAddress addr = channel.remoteAddress();       channel.writeAndFlush(request).addListener(new ChannelFutureListener() {        @Override        public void operationComplete(ChannelFuture f) throws Exception {           if (f.isSuccess()) {              responseFuture.setSendRequestOK(true);             return;          } else {             responseFuture.setSendRequestOK(false);          }          responseTable.remove(opaque);          responseFuture.setCause(f.cause());          responseFuture.putResponse(null);           log.warn("send a request command to channel <" + addr + "> failed.");       }     });   RemotingCommand responseCommand =       responseFuture.waitResponse(timeoutMillis);       if (null == responseCommand) {          if (responseFuture.isSendRequestOK()) {            throw new RemotingTimeoutException(RemotingHelper.parseSocketAddressAddr(addr), timeoutMillis, responseFuture.getCause());          } else {            throw new RemotingSendRequestException(RemotingHelper.parseSocketAddressAddr(addr), responseFuture.getCause());          }        }         return responseCommand;    } finally {        this.responseTable.remove(opaque);     }}

rocketmq封装了 responseFuture 对象超时设置通过countdown来实现超时效果

public RemotingCommand waitResponse(final long timeoutMillis) throws InterruptedException {    this.countDownLatch.await(timeoutMillis, TimeUnit.MILLISECONDS);    return this.responseCommand;}