我工作这几年（五）-- 在代码中加入一些关键统计信息来实时监控程序的运行状态

原创链接：http://blog.csdn.net/zhao_3546/article/details/18941649，转载请注明。

我工作这几年（五）-- 在代码中加入一些关键统计信息来实时监控程序的运行状态

在上一篇《我工作这几年（四） --解决短信平台OutOfMemory问题及收获》中，分析了在出现OutOfMemory问题后，如何通过性能测试重现问题后再解决问题，但通过这种方式去解决问题比较被动，那如何能主动地让问题及时地暴露出来呢？

一般我们在写代码过程中都会输出很多日志，但是在现网运行时，只会放开INFO级别以上的日志，OutOfMomery问题要出现一般都需要一个比较持续的过程才行，所以即使是INFO以上级别的日志，服务器运行持续一段时间后，也会有非常多日的志，要根据这么多日志反推业务的运行过程，还是非常困难的。

那我们尝试换一个角度，我们是否可以尝试把业务的运行过程记录下来呢？

 

通过下面这个图我们再简单地还原下业务的运行过程：

MsgAgent内部主要运行逻辑再简单地总结下，更详细的介绍可以看这个《我工作这几年（三） --实现短信平台》：

1、  通过http接口，对外暴露短信发送的能力；

2、  对收到的请求进行一定的处理中，包装成一个Bean对象M插入到消息队列中；

3、  短信处理线程从消息队列中取出Bean，将消息送给短信协议栈进一步处理；

4、  短信协议栈返回短信响应后，该短信消息对象M会被缓存到ehcache中；

5、  短信协议栈收到短信回执后，处理短信回执；

6、  短信对象M入库；

 

这样一个业务流程，我们如何将其运行时过程记录下来呢？

从上面的业务流程，可以总结出几个关键点：短信发送接口、短信消息队列、将短信转交给短信协议栈处理、从短信协议栈接收短信响应、从短信协议栈接收回执、短信响应及回执队列、短信对象入库。

只要在这些关键点加上相应的监控即可。那如何监控呢？

监控主要分4点：

1、  运行次数监控；

2、  关键资源监控；

3、  运行时长监控；

 

下面我分别就上面说的几点一一介绍：

一、运行次数监控

这个理解起来比较简单，比如我们对外提供了短信发送能力，第三方到底调用了多少次；又比如我们还会将短信对象交给短信协议栈进一步地处理，我们调用了短信协议栈的接口多少次，等等。

二、关键资源监控

上面列出的关键点中，其实有列出了消息队列、短信响应及回执队列等，这些全局的消息队列就是关键资源。

三、运行时长监控

运行时长比较好理解，像短信对象入库等这些操作，涉及到IO操作，可能就会存在瓶颈，因此要格外关注。

加上这些监控点，通过将这些监控点收集到的数据及时地输出，我们就可以比较实时地了解系统的运行情况了。通过比较第三方调用我们短信发送接口的次数，及我们将短信对象交给短信协议栈的处理次数，我们就可以很及时了解到系统在处理过程中有没有丢消息；通过查看消息队列的大小，我们就可以很实时地了解当前系统的处理能力有没有达到阀值，如果消息队列在一段时间内一直是满的，则说明系统已经处理不过来了；通过分析短信入库操作的耗时区间分布，我们也可以及时地了解数据库是否出现了问题；另外，通过这些定时数据，我们也可以得到系统的运行数据，比如系统一般在什么时间点会出现短信发送的峰值，短信发送的峰值会达到多少等。

说了这么多，下面来点干货，看看我们之前的这个监控的代码是如何实现的。

HPCounter 的实现如下：

package com.zhao3546.monitor;

import java.util.Collection;
import java.util.Map;
import java.util.Timer;
import java.util.concurrent.ConcurrentHashMap;
import java.util.logging.Level;
import java.util.logging.Logger;

/**
 * 高性能数据计数器 (HP --> High Performance)
 */
public class HPCounter {
    private static final Logger LOG = Logger.getLogger(HPCounter.class
            .getName());

    /**
     * 计数器容器
     */
    private final static ConcurrentHashMap<Thread, int[]> threadTimeMap = new ConcurrentHashMap<Thread, int[]>();

    /**
     * 初始化计数器设置
     */
    public static void init() {
        if (LOG.isLoggable(Level.FINE)) {
            LOG.fine("initialize HPCounter");
        }

        startStaticsThread();
    }

    private static String[] timeCounterNames = new String[16];

    public static void register(String name, int index) {
        synchronized (HPCounter.class) {
            if (timeCounterNames.length <= index) {
                String[] names = new String[index + 1];
                for (int i = 0; i < timeCounterNames.length; ++i) {
                    names[i] = timeCounterNames[i];
                }
                timeCounterNames = names;
            }

            timeCounterNames[index] = name;
        }
    }

    private static ConcurrentHashMap<String, Collection<Object>> collectionMap = new ConcurrentHashMap<String, Collection<Object>>();

    public static void register(String name, Collection<Object> collection) {
        synchronized (HPCounter.class) {
            collectionMap.put(name, collection);
        }
    }

    /**
     * 累计指定计数器
     * 
     * @param index
     *            要增加的某个计数器索引
     */
    public static void increase(int index) {
        Thread thread = Thread.currentThread();
        int[] counter = threadTimeMap.get(thread);
        if (counter == null) {
            counter = threadTimeMap.get(thread);
            if (counter == null) {
                counter = new int[timeCounterNames.length];
                for (int i = 0; i < timeCounterNames.length; ++i) {
                    counter[i] = 0;
                }
                threadTimeMap.put(thread, counter);
            }
        }

        ++counter[index];
    }

    /**
     * 输出计数器内容到RTP日志中 【注意】只输出设置了名称的计数器数据.
     * 
     * @param strBuf
     */
    public void appendInfo(StringBuffer strBuf) {
        System.out.println("Service HPCounter Statistics Information");
        System.out
                .println("-----------------------------------------------------------------");

        // time
        long[] counter = new long[timeCounterNames.length];
        int[][] timeArray = new int[threadTimeMap.size()][]; // threadTimeMap.size()对应线程数
        threadTimeMap.values().toArray(timeArray);

        for (int i = 0; i < timeArray.length; i++) {
            for (int j = 0; j < timeCounterNames.length; j++) {
                counter[j] = counter[j] + timeArray[i][j];
            }
        }
        for (int i = 0; i < timeCounterNames.length; ++i) {
            if (timeCounterNames[i] != null) {
                System.out.println(timeCounterNames[i] + " : " + counter[i]);
            }
        }

        // collection
        for (Map.Entry<String, Collection<Object>> e : collectionMap.entrySet()) {
            System.out.println(e.getKey() + " size : " + e.getValue().size());
        }

        System.out
                .println("-----------------------------------------------------------------");
        System.out.println();
        System.out.println();
    }

    /**
     * 启动统计线程
     */
    private static final void startStaticsThread() {
        Timer timer = new Timer();
        timer.schedule(new StaticsThread(), 1000, 5 * 1000);
    }
}

这个是主要实现类，相关计数的实现，在第一次完成之后，都是无锁操作，对性能没有影响，也经过了现网验证。

完整的工程，已经上传了csdn的资源库，见这里： http://download.csdn.net/detail/zhao3546/6900409。

工程的运行结果如下：

Service HPCounter Statistics Information
-----------------------------------------------------------------
RECEIVE_REQUESTS : 2
INSERT_INTO_MSG_QUEUE : 2
REDIRECT_TO_SMS_STACK : 1
msg2DBQueue size : 0
msgQueue size : 1
-----------------------------------------------------------------


Service HPCounter Statistics Information
-----------------------------------------------------------------
RECEIVE_REQUESTS : 39
INSERT_INTO_MSG_QUEUE : 39
REDIRECT_TO_SMS_STACK : 37
msg2DBQueue size : 0
msgQueue size : 2
-----------------------------------------------------------------

...

有了上面的结果，我们可以使用Excel来进一步分析，可以得到下面的结果，如图：

另外一些主要队列的大小，在统计信息中，都有输出，通过观察一段时间的这个数据，也可以进一步分析程序的运行状态。

由于时间关系， 运行时长监控的实现代码，暂未实现。

程序运行状态监控的想法和代码原型，来自于我之前的一个老大，也是我进公司这么久最佩服的一个技术牛人，基本上没有他搞不定的问题，跟着他我学了太多的东西，我也成长了很多。