简易版Dubbo方法级性能监控思路及讲解

简易版Dubbo方法级性能监控思路及讲解

完整代码在这里简易版Dubbo方法级性能监控
以下是讲解

一、 要求

在真实业务场景中，经常需要对各个业务接口的响应性能进行监控（常用指标为：TP90、TP99）

下面通过扩展Dubbo的Filter（TPMonitorFilter），完成简易版本 Dubbo 接口方法级性能监控，记录下TP90、TP99请求的耗时情况。

题目要求：

1. 编写一个Dubbo服务，提供3个方法（methodA、methodB、methodC），每方法都实现了随机休眠0-100ms

2. 编写一个消费端程序，不断调用Dubbo服务的3个方法（建议利用线程池进行并行调用，确保在1分钟内可以被调用2000次以上）

3. 利用TPMonitorFilter在消费端记录每个方法的请求耗时时间（异步调用不进行记录）

4. 每隔5s打印一次最近1分钟内每个方法的TP90、TP99的耗时情况

二、要求分析及实现思路

1.分析

是主要的是弄明白TP90、TP99的含义，然后实现出来

TP90、TP99含义：

假设你统计了一段时间内访问系统的100次请求数据，他们的响应耗时分别是：1ms、2ms、3ms…100ms。
基于本次统计结果，你系统的 TP90，请求耗时从小到大排列，取第 100*0.9次请求耗时 ，为90ms（代表 90% 请求响应不超过90ms），类似地 TP50=50ms、TP99=99ms。

含义搞明白之后，计算TP90、TP99的逻辑也较简单。

2. 实现思路

1. 首先创建一个Java Bean即即MonitorMethodInfo用来保存每个方法每次调用的当前时间、耗时信息。
2. 在TPMonitorFilter中的实现
   1. 集合中记录每次方法调用的监控信息即MethodMonitorInfo
   2. 使有Executors.newSingleThreadScheduledExecutor()每隔5s打印一次最近1分钟内每个方法的TP90、TP99的耗时情况。

三、具体实现

1. 项目结构

• homework-dubbo
  • service-api
  • service-consumer
  • service-provider
  • service-monitor

新添加了service-monitor项目，TPMonitorFilter在这个项目里，然后将serivce-monitor引入到service-consumer里。

2. HelloService实现

提供3个方法methodA、 methodB、 methodC，并且随机休眠0-100ms。

@Service
public class HelloServiceImpl implements HelloService {

    private Random random = new Random();

    private void sleep(int bound) {
        try {
            Thread.sleep(random.nextInt(bound));
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }

    @Override
    public String methodA() {
        sleep(100);
        return "methodA被调用了";
    }

    @Override
    public String methodB() {
        sleep(100);
        return "methodB被调用了";
    }

    @Override
    public String methodC() {
        sleep(100);
        return "methodC被调用了";
    }

}

3. HelloComponent

@Component
public class HelloComponent {

    @Reference(timeout = 10000)
    private HelloService helloService;

    /**
     * 调用methodA、methodB、methodC这三个方法
     */
    public String callABC(char c) {
        if ('A' == c) {
            return helloService.methodA();
        } else if ('B' == c) {
            return helloService.methodB();
        } else {
            return helloService.methodC();
        }
    }
}

4. ServiceConsumerMain

循环使用多线程调用methodA、methodB、methodC这三个方法

public class ServiceConsumerMain {

    private static final ExecutorService EXECUTOR_SERVICE = Executors.newFixedThreadPool(6);

    public static void main(String[] args) throws IOException {
        System.out.println("-------------");
        AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext(ConsumerConfiguration.class);
        context.start();
        // 获取消费者组件
        HelloComponent component = context.getBean(HelloComponent.class);
        System.out.println("请输入回车，开始调用服务");
        System.in.read();
        while (true) {
            EXECUTOR_SERVICE.submit(() -> component.callABC('A'));
            EXECUTOR_SERVICE.submit(() -> component.callABC('B'));
            EXECUTOR_SERVICE.submit(() -> component.callABC('C'));
            try {
                Thread.sleep(60);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }

    @Configuration
    @ComponentScan("com.mh.study.dubbo.component")
    @EnableDubbo(scanBasePackages = "com.mh.study.dubbo.service")
    @PropertySource("classpath:/dubbo-consumer.properties")
    static class ConsumerConfiguration {
    }
}

以上是为测试TP90、TP99对provider和consumer的改造，下面是具体实现TP90、TP99的代码

5. MethodCalledTimeInfo

记录方法调用时间信息的类

@Data
@AllArgsConstructor
public class MethodCalledTimeInfo{

    /**
     * 方法名
     */
    private String methodName;
    /**
     * 调用结束时间
     */
    private long calledEndTime;
    /**
     * 花费时间
     */
    private long spendTime;

    /**
     * 此次调是否在开始时间和结束时间范围内
     * true是false不是
     */
    public boolean endTimeBetween(long startTime, long endTime) {
        return calledEndTime >= startTime && calledEndTime <= endTime;
    }
}

6. TPMonitorFilter实现

给消费添者添加上此过滤器，并交给PDPrintHelper打印PD90、PD99

@Activate(group = CommonConstants.CONSUMER)
public class TPMonitorFilter implements Filter {

    /**
     * PD90、PD99信息打印帮助者
     */
    private PDPrintHelper pdPrintHelper = new PDPrintHelper();

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        try {
            long startTime = System.currentTimeMillis();
            // 执行方法
            Result result = invoker.invoke(invocation);
            long endTime = System.currentTimeMillis();
            // 保存本次方法调用时间信息，并触发打印PD90、PD99
            pdPrintHelper.put(new MethodCalledTimeInfo(invocation.getMethodName(), startTime, endTime - startTime));
            System.out.println(result.getValue() + ", 耗时: " + (endTime - startTime) + "ms");
            return result;
        } catch (Exception e) {
            e.printStackTrace();
            throw e;
        }
    }
}

在service-monitor下创建文件resources\META-INF\dubbo\org.apache.dubbo.rpc.Filter

内容为：

monitorFilter=com.mh.study.dubbo.filter.TPMonitorFilter

7. PDPrintHelper

由此类实现打印PD90、PD99

public class PDPrintHelper {

    /**
     * 方法每次被调用时间,以方法名分组
     * key是方法名，value是方法被调用的时间信息
     */
    private final Map<String, List<MethodCalledTimeInfo>> calledTimeInfoMap = new HashMap<>();

    /**
     * true表示已开始打印
     */
    private volatile boolean startedPrint;

    public void put(MethodCalledTimeInfo monitorMethodInfo) {
        // 当发起第一次调用后，开始每隔5s打印TP90和TP99
        triggerPrint();
        String methodName = monitorMethodInfo.getMethodName();
        if (!calledTimeInfoMap.containsKey(methodName)) {
            calledTimeInfoMap.put(methodName, new ArrayList<>());
        }
        calledTimeInfoMap.get(methodName).add(monitorMethodInfo);
    }

    /**
     * 当发起第一次调用后，开始每隔5s打印TP90和TP99
     */
    private void triggerPrint() {
        if (!startedPrint) {
            startedPrint = true;
            Executors.newSingleThreadScheduledExecutor()
                    .scheduleWithFixedDelay(this::printTP, 5, 5, TimeUnit.SECONDS);
        }
    }

    private void printTP() {
        if (calledTimeInfoMap.size() == 0) {
            return;
        }
        LocalDateTime now = LocalDateTime.now();
        long currentTime = System.currentTimeMillis();
        long oneMinuteAgoTime = currentTime - 60000;
        calledTimeInfoMap.forEach((methodName, calledTimeInfos) -> {
            List<MethodCalledTimeInfo> sortedList = calledTimeInfos.stream()
                    // 筛选出一分钟以内的调用
                    .filter(info -> info.endTimeBetween(oneMinuteAgoTime, currentTime))
                    // 按耗时升序排序
                    .sorted(Comparator.comparingLong(MethodCalledTimeInfo::getSpendTime))
                    .collect(Collectors.toList());
            long tp90 = sortedList.get((int) (sortedList.size() * 0.9)).getSpendTime();
            long tp99 = sortedList.get((int) (sortedList.size() * 0.99)).getSpendTime();
            System.out.printf("【%s】-【%s】,TP90: %sms,TP99: %sms\n", now, methodName, tp90, tp99);
        });
    }

}

四、结果验证

methodA被调用了, 耗时: 54ms
methodC被调用了, 耗时: 67ms
methodA被调用了, 耗时: 123ms
methodC被调用了, 耗时: 126ms
methodB被调用了, 耗时: 25ms
methodB被调用了, 耗时: 102ms

省略若干行日志...

methodA被调用了, 耗时: 32ms
methodC被调用了, 耗时: 84ms
methodA被调用了, 耗时: 46ms
【2022-02-14T22:00:08.140874500】-【methodA】,TP90: 98ms,TP99: 123ms
【2022-02-14T22:00:08.140874500】-【methodB】,TP90: 88ms,TP99: 160ms
【2022-02-14T22:00:08.140874500】-【methodC】,TP90: 87ms,TP99: 126ms
methodC被调用了, 耗时: 60ms
methodB被调用了, 耗时: 63ms
methodA被调用了, 耗时: 11ms
methodC被调用了, 耗时: 44ms
methodB被调用了, 耗时: 64ms

省略若干行日志...

methodC被调用了, 耗时: 50ms
methodB被调用了, 耗时: 12ms
methodA被调用了, 耗时: 22ms
methodC被调用了, 耗时: 22ms
methodC被调用了, 耗时: 4ms
methodA被调用了, 耗时: 35ms
methodB被调用了, 耗时: 35ms
【2022-02-14T22:00:13.150810400】-【methodA】,TP90: 88ms,TP99: 102ms
【2022-02-14T22:00:13.150810400】-【methodB】,TP90: 93ms,TP99: 102ms
【2022-02-14T22:00:13.150810400】-【methodC】,TP90: 93ms,TP99: 103ms

省略若干行日志...