19&20丨Java & C ++：代码级监控及常用计数器解析

19丨Java & C ++：代码级监控及常用计数器解析（上）

在性能测试分析中，有一部分人存在着一个思路上的误解，那就是一开始就一头扎进代码里，折腾代码性能。这是我非常反对的一种做法。

事实上，要想这么做，有一个前提，那就是架构中的其他组件都经过了千锤百炼，出现问题的可能性极低。

实际上，我凭着十几年的经验来看，大部分时候，代码出现严重性能瓶颈的情况还真是不多。再加上现在成熟的框架那么多，程序员们很多情况下只写业务实现。在这种情况下，代码出现性能瓶颈的可能性就更低了。

但我们今天终归要说代码级的监控及常用的计数器。如何去评估一个业务系统的代码性能呢？在我看来，分析的思路是下面这个样子的。

从上图可以看到，分析的时候有两个关键点：执行时间和执行空间。我相信很多人都清楚，我们要很快找到执行时间耗在哪一段和空间耗在哪里。

现在我们来实际操作一下，看如何判断。

Java 类应用查找方法执行时间

首先你得选择一个合适的监控工具。Java 方法类的监控工具有很多，这里我选择 JDK 里自带的 jvisualvm。

顺便说一下，我的 Java 版本号是这个：

(base) GaoLouMac:~ Zee$ java -version
java version "1.8.0_111"
Java(TM) SE Runtime Environment (build 1.8.0_111-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.111-b14, mixed mode)

打开应用服务器上的 JMX 之后，连上 jvisualvm，你会看到这样的视图。

这里再啰嗦一下我们的目标，这时我们要找到消耗 CPU 的方法，所以要先点Sampler - CPU，你可以看到如下视图。

从上图可以看到方法执行的累积时间，分别为自用时间百分比、自用时间、自用时间中消耗 CPU 的时间、总时间、总时间中消耗 CPU 的时间、样本数。

从这些数据中就可以看到方法的执行效率了。

但是，这里面 Method 这么多，我怎么知道哪个跟我的方法执行时间有关呢？比如说上面这个应用中，最消耗 CPU 的是 JDBC 的一个方法 fill。这合理吗？

先来看一下我的脚本。

从结构上你就能看出来，我做了登录，然后就做了创建的动作，接着就退出了。

这几个操作和数据库都有交互。拿 create 这个步骤来说，它的脚本非常直接，就是一个 POST 接口。

还记得前面我们怎么说查看后端的运行逻辑的吗？后端接收这个 POST 的代码如下：

​

    @RequestMapping("/save")
    @ResponseBody
    public Object save(Blog blog, HttpSession session){
   
        try{
   
            Long id = blog.getId();
            if(id==null){
   
                User user = (User)session.getAttribute("user");
                blog.setAuthor(user.getName());
                blog.setUserId(user.getId());
                blog.setCreateTime(new Date());
                blog.setLastModifyTime(new Date());
                blogWriteService.create(blog);
            }else {
   
                blog.setLastModifyTime(new Date());
                blogWriteService.update(blog);
            }
        }catch (Exception e){
   
            throw new JsonResponseException(e.getMessage());
        }
        return true;
    }

这段代码的功能就是讲前端内容接收过来放到实体中，然后通过 create 方法写到数据库中。那么 create 是怎么实现的呢？

    public void  create(Blog blog) {
   
        mapper.insert(blog);
        BlogStatistics blogStatistics = new BlogStatistics(blog.getId());
        blogStatisticsMapper.insert(blogStatistics);

它就是一个 mapper.insert，显然这个 create 是我们自己实现的代码，里面其实没有什么逻辑。而 ReadAheadInputStream.fill 是 create 中的 MyBatis 调用的 JDBC 中的方法。 从压力工具到数据库的调用逻辑就是：

而我们看到的最耗时的方法是最后一个，也就是 fill。实际上，我们应该关心的是 save 接口到底怎么样。我们来过滤下看看。

从 save 的结果上来看，它本身并没有耗什么时间，都是后面的调用在消耗时间。

我们再来看看 cerate。

它本身也没消耗什么时间。

顺着逻辑图，我们再接着看 MyBatis 中的 insert 方法。

就这样一层层找下去，最后肯定就找到了 fill 这个方法了。但是你怎么知道整个调用逻辑中有哪些层级呢？你说我可以看源码。当然不是不可以。但要是没有源码呢？做性能分析的人经常没有源码呀。

这个时候，我们就要来看栈了。这里我打印了一个调用栈，我们来看下这个逻辑。

"http-nio-8080-exec-1" - Thread t@42
   java.lang.Thread.State: RUNNABLE
  ...............
  at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:100)
    ..