Spring-AOP實踐 - 統計訪問時間

時間 2019-11-18

標籤 spring aop 實踐統計訪問時間欄目 Spring 简体版

原文原文鏈接

公司的項目有的頁面超級慢，20s以上，不知道用戶會不會瘋掉，因而老大說這個頁面要性能優化。因而，首先就要搞清楚到底是哪一步耗時太多。html

我採用spring aop來統計各個階段的用時，其中計時器工具爲StopWatch。java

文章結構：git

其中，遇到的問題:

1.少包aspectjweavergithub

添加依賴後纔可使用@Aspectweb

2.環繞通知加入多個pointspring

剛開使用&&鏈接多個point，傻傻的看不到調用，突然看到要用||纔對數據庫

3.監聽時間工具StopWatch每次只能啓動一個，必定要關閉後才能啓動下一個。apache

而我想要測試controller->service->repository各個階段用時顯然很不適應。由於使用同一個stopwatch對象來保存時間，而stopwatch每次只能記錄一個時間段做爲總時間的一部分，不存在時間嵌套關係（這個之後能夠考慮想一想別的方案）。controller開始後執行部分驗證邏輯或是其餘，而後調用service，這時候service啓動定時會失敗，由於controller的計時器還沒關，所以須要先關掉controller的計時器。這樣會致使controller的計時部分僅僅是調用service以前的時間，service返回值以後，controller再進行某些處理的時間並無統計。顯然，我須要一個卡表的時間統計設計，即進入controller開始計時，調用service後開始service計時，以此類推，最後得到controller總時間Tc，service總時間Ts，repository總時間Tr.因此時間統計應該如圖1：json

圖一圖二api

這樣的話，我應該分別得到Tc,Ts,Tr的時間，而後計算百分比或者別的統計工做。也就是說，log僅僅是log，記錄而已，想要獲得一個統計結果還須要針對數據二次開發，這就須要將時間存儲起來或者進行日誌挖掘，然而這統計的工做會愈來愈複雜，最終我都不知會加多少任務進去。

事實上，咱們這個頁面耗費時間主要是多個webservice調用產生的io耗時，也就是說其實統計一個層面的時間就差很少了。那麼，忽略service返回後controller的其餘時間，僅僅計算controller開始到調用service的時間爲Tc,service開始到調用repository的時間爲Ts，如圖2，這樣利用StopWatch就很容獲取時間統計結果。

4.線程不安全

我竟然使用單例的一個成員變量作狀態存儲，真是。待改進

1.搭建項目

採用spring-boot-aop的框架來搭建。最終結構圖以下：

1.1在idea中，new project-》maven

1.2初始化pom，添加aop，web，test依賴：

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.test</groupId>
    <artifactId>spring-aop</artifactId>
    <version>1.0-SNAPSHOT</version>
    <dependencyManagement>
        <dependencies>
            <dependency>
                <!-- Import dependency management from Spring Boot -->
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-dependencies</artifactId>
                <version>1.3.5.RELEASE</version>
                <type>pom</type>
                <scope>import</scope>
            </dependency>
        </dependencies>
    </dependencyManagement>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-aop</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.assertj</groupId>
            <artifactId>assertj-core-java8</artifactId>
            <version>1.0.0m1</version>
        </dependency>
    </dependencies>
    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
        </plugins>
    </build>

</project>

1.3建立啓動入口：com.test.spring.aop.Application.java

package com.test.spring.aop;

import com.test.spring.aop.domain.service.IHelloService;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.CommandLineRunner;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

/**
 * Created by miaorf on 2016/7/16.
 */
@SpringBootApplication
public class Application implements CommandLineRunner{

    @Autowired
    IHelloService helloService;

    public void run(String... strings) throws Exception {
        System.out.println("start application by CommandLineRunner, the args:"+strings.length);
        helloService.sayHi();
    }

    public static void main(String[] args) throws Exception {
        SpringApplication.run(Application.class, args);
    }
}

1.4發現咱們須要一個service:

建立com.test.spring.aop.domain.service.IHelloService

package com.test.spring.aop.domain.service;

/**
 * Created by miaorf on 2016/7/16.
 */
public interface IHelloService {
    void sayHi();
}

建立com.test.spring.aop.domain.service.impl.HelloService

package com.test.spring.aop.domain.service.impl;

import com.test.spring.aop.domain.service.IHelloService;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.stereotype.Service;

/**
 * Created by miaorf on 2016/7/16.
 */
@Service
public class HelloService implements IHelloService {

    @Value("${name}")
    private String name;

    public void sayHi() {
        for (int i = 0; i < 100000; i++) {

        }
        System.out.println("Hi "+name);
        System.out.println("I'm  running.");
    }
}

1.5發現咱們須要一個屬性配置文件：

建立application.yml

1 name: Ryan

View Code

1.6這時候能夠測試一下啓動看看了

直接啓動：運行com.test.spring.aop.Application#main()便可。

命令行啓動：mvn spring-boot:run，

命令行bug啓動：mvn spring-boot:run -Drun.jvmArguments="-Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=y,address=5005"

1.7建立測試com.test.spring.aop.ApplicationTest

package com.test.spring.aop;

import org.junit.After;
import org.junit.Before;
import org.junit.Rule;
import org.junit.Test;
import org.springframework.boot.test.OutputCapture;

import static org.assertj.core.api.Assertions.assertThat;


/**
 * Created by miaorf on 2016/7/16.
 */
public class ApplicationTest {
    @Rule
    public OutputCapture outputCapture = new OutputCapture();

    private String profiles;

    @Before
    public void init() throws Exception {
        this.profiles = System.getProperty("spring.profiles.active");
    }

    @After
    public void tearDown() throws Exception {
        if (this.profiles != null){
            System.setProperty("spring.profiles.active",this.profiles);
        }else{
            System.out.println("spring.profiles.active");
        }
    }

    @Test
    public void testDefaultSettings() throws Exception{
        Application.main(new String[0]);
        String s = this.outputCapture.toString();
        assertThat(s).contains("Hi Ryan");
    }
    @Test
    public void testCommandLineOverrides() throws Exception {
        Application.main(new String[] {"--name=Leslie"});
        String s = this.outputCapture.toString();
        assertThat(s).contains("Hi Leslie");
    }


}

View Code

2.AOP - HelloWorld

2.1建立com.test.spring.aop.monitor.ServiceMonitor

package com.test.spring.aop.monitor;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;

/**
 * Created by miaorf on 2016/7/16.
 */
@Aspect
@Component
public class ServiceMonitor {

    private static Logger logger = LoggerFactory.getLogger(ServiceMonitor.class);

    StopWatch stopWatch = new StopWatch("performance");

    /**
     * define point
     */
    @Pointcut("execution(* com.test.spring.aop..*Service.*(..))")
    public void performance(){}

//    @Before("performance()")
//    public void startService(){
//        System.out.println("-----------service start-------");
//    }
//    @After("performance()")
//    public void endService(){
//        System.out.println("-----------service end neither success or failed -------");
//    }
//
//    @AfterReturning("performance()")
//    public void logServiceAccess(JoinPoint joinPoint) {
//        System.out.println("service completed:"+joinPoint);
//    }

    /**
     * 必需要返回，否則後面收不到
     * @param point
     * @return
     */
    @Around("performance()")
    public Object watchPerformance(ProceedingJoinPoint point){
        System.out.println("The service start:");

        stopWatch.start(point.getSignature().toString());
        try {
            return point.proceed();
        } catch (Throwable throwable) {
            logger.error("The service not work!",throwable);
            throwable.printStackTrace();
        }finally {
            stopWatch.stop();
            stopWatch.start("b");
            for (int i = 0; i < 12345; i++) {

            }
            stopWatch.stop();
            StopWatch.TaskInfo[] taskInfo = stopWatch.getTaskInfo();
            for (StopWatch.TaskInfo info : taskInfo) {
                System.out.println(info.getTaskName());
                System.out.println(info.getTimeMillis());
            }
            logger.info("The {} run time:{}",point.getSignature().toString(),stopWatch.prettyPrint());
        }

        return null;
    }
}

View Code

2.2測試

測試水平還沒開始，因此只能手動測試了，運行com.test.spring.aop.ApplicationTest能夠看到在HelloService調用先後插入了日誌。

3.時間統計

最終，生成類圖以下：

最終得到的時間統計以下：

2016-07-16 21:25:09.361  INFO 16824 --- [nio-8080-exec-4] com.test.spring.aop.monitor.UserMonitor  : StopWatch 'controller': running time (millis) = 3218
-----------------------------------------
ms     %     Task name
-----------------------------------------
01001  031%  List com.test.spring.aop.domain.service.IUserService.getAll()
02000  062%  Object com.test.spring.aop.domain.repository.IConnector.getSthFromRemote()
00217  007%  List com.test.spring.aop.domain.repository.IUserDao.getAll()

3.1須要設計一個controller

建立com.test.spring.aop.web.UserController：

package com.test.spring.aop.web;

import com.test.spring.aop.domain.entiry.User;
import com.test.spring.aop.domain.service.IUserService;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Controller;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.ResponseBody;

import java.util.List;

/**
 * Created by miaorf on 2016/7/16.
 */
@Controller
@RequestMapping("/user")
public class UserController {

    @Autowired
    private IUserService userService;

    @ResponseBody
    @RequestMapping("/all")
    public List<User> users(){
        try {Thread.sleep(1000);} catch (InterruptedException e) {e.printStackTrace();}
        List<User> all = userService.getAll();
        return all;
    }
}

View Code

3.2發現須要一個service

建立com.test.spring.aop.domain.service.IUserService

package com.test.spring.aop.domain.service;

import com.test.spring.aop.domain.entiry.User;

import java.util.List;

/**
 * Created by miaorf on 2016/7/16.
 */
public interface IUserService {

    List<User> getAll();
}

View Code

建立com.test.spring.aop.domain.service.impl.UserService

package com.test.spring.aop.domain.service.impl;

import com.test.spring.aop.domain.entiry.User;
import com.test.spring.aop.domain.repository.IConnector;
import com.test.spring.aop.domain.repository.IUserDao;
import com.test.spring.aop.domain.service.IUserService;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Service;

import java.util.List;

/**
 * Created by miaorf on 2016/7/16.
 */
@Service
public class UserService implements IUserService {

    @Autowired
    private IUserDao userDao;

    @Autowired
    private IConnector connector;

    public List<User> getAll() {
        try {Thread.sleep(1000);} catch (InterruptedException e) {e.printStackTrace();}
        connector.getSthFromRemote();
        return userDao.getAll();
    }
}

View Code

3.3發現須要一個repository

建立com.test.spring.aop.domain.repository.IUserDao

package com.test.spring.aop.domain.repository;

import com.test.spring.aop.domain.entiry.User;

import java.util.List;

/**
 * Created by miaorf on 2016/7/16.
 */
public interface IUserDao {

    List<User> getAll();
}

View Code

建立com.test.spring.aop.domain.repository.impl.UserDao

package com.test.spring.aop.domain.repository.impl;

import com.test.spring.aop.domain.entiry.User;
import com.test.spring.aop.domain.repository.IUserDao;
import org.springframework.stereotype.Repository;

import java.util.ArrayList;
import java.util.List;

/**
 * Created by miaorf on 2016/7/16.
 */
@Repository
public class UserDao implements IUserDao {


    public List<User> getAll() {
        //mock data
        List<User> list = new ArrayList<User>(10000);
        for (int i = 0; i < 10000; i++) {
            list.add(new User(i,"name_"+i,getRondomString(6),i,i%2,getRondomString(100)));
        }
        return list;
    }

    private String getRondomString(int length){
        StringBuffer buf = new StringBuffer("a,b,c,d,e,f,g,h,i,g,k,l,m,n,o,p,q,r,s,t,u,v,w,x,y,z");
        buf.append(",A,B,C,D,E,F,G,H,I,G,K,L,M,N,O,P,Q,R,S,T,U,V,W,X,Y,Z");
        buf.append(",~,@,#,$,%,^,&,*,(,),_,+,|,`,.");
        buf.append(",1,2,3,4,5,6,7,8,9,0");
        String[] arr = buf.toString().split(",");

        StringBuffer result = new StringBuffer();
        for (int i = 0; i < length; i++) {
            int random = (int) (Math.random() * 10000 + 1);
            result.append(arr[random % arr.length]);
        }

        return result.toString();
    }



}

View Code

3.3.1臨時添加一個遠程調用

建立com.test.spring.aop.domain.repository.IConnector

package com.test.spring.aop.domain.repository;

/**
 * Created by miaorf on 2016/7/16.
 */
public interface IConnector {

    Object getSthFromRemote();
}

View Code

建立com.test.spring.aop.domain.repository.impl.Connector

package com.test.spring.aop.domain.repository.impl;

import com.test.spring.aop.domain.repository.IConnector;
import org.springframework.stereotype.Component;

/**
 * Created by miaorf on 2016/7/16.
 */
@Component
public class Connector implements IConnector {

    public Object getSthFromRemote() {
        //mock time
        try {Thread.sleep(2000);} catch (InterruptedException e) {e.printStackTrace();}
        return null;
    }
}

View Code

3.4發現須要一個實體類

建立com.test.spring.aop.domain.entiry.User

package com.test.spring.aop.domain.entiry;

/**
 * Created by miaorf on 2016/7/16.
 */
public class User {
    Integer id;
    String username;
    String password;
    Integer age;
    Integer sex;
    String info;

    public User() {
    }

    public User(Integer id, String username, String password, Integer age, Integer sex, String info) {
        this.id = id;
        this.username = username;
        this.password = password;
        this.age = age;
        this.sex = sex;
        this.info = info;
    }

    public Integer getId() {
        return id;
    }

    public void setId(Integer id) {
        this.id = id;
    }

    public String getUsername() {
        return username;
    }

    public void setUsername(String username) {
        this.username = username;
    }

    public String getPassword() {
        return password;
    }

    public void setPassword(String password) {
        this.password = password;
    }

    public Integer getAge() {
        return age;
    }

    public void setAge(Integer age) {
        this.age = age;
    }

    public Integer getSex() {
        return sex;
    }

    public void setSex(Integer sex) {
        this.sex = sex;
    }

    public String getInfo() {
        return info;
    }

    public void setInfo(String info) {
        this.info = info;
    }

    @Override
    public String toString() {
        return "User{" +
                "id=" + id +
                ", username='" + username + '\'' +
                ", password='" + password + '\'' +
                ", age=" + age +
                ", sex=" + sex +
                ", info='" + info + '\'' +
                '}';
    }
}

View Code

3.5完成

以上就基本把一個web接口搞定了，能夠運行測試一下，使用瀏覽器或者postman訪問localhost:8080/user/all就能夠得到user列表了。

3.6加入user時間統計

建立com.test.spring.aop.monitor.UserMonitor

package com.test.spring.aop.monitor;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;

/**
 * Created by miaorf on 2016/7/16.
 */
@Aspect
@Component
public class UserMonitor {

    private static Logger logger = LoggerFactory.getLogger(UserMonitor.class);
    StopWatch stopWatch;

    @Pointcut("execution(* com.test.spring.aop.web.UserController.users())")
    public void controllerPerformance() {
    }

    @Pointcut("execution(* com.test.spring.aop.domain.service.impl.UserService.getAll())")
    public void servicePerformance() {
    }

    @Pointcut("execution(* com.test.spring.aop.domain.repository.impl.UserDao.getAll())")
    public void repositoryPerformance() {
    }

    @Pointcut("execution(* com.test.spring.aop.domain.repository.impl.Connector.getSthFromRemote())")
    public void connectorPerformance() {
    }

    @Before("controllerPerformance()")
    public void startWatch() {
        stopWatch = new StopWatch("controller");
    }

    @After("controllerPerformance()")
    public void endWatch() {
        logger.info(stopWatch.prettyPrint());
        stopWatch = null;
    }

    @Around("servicePerformance() || repositoryPerformance() || connectorPerformance()")
    public Object watchPerformance(ProceedingJoinPoint joinPoint) throws Throwable {
        System.out.println("---------------------------");
        try {
            //若是是一層一層的，這裏只能統計到到下一層須要的時間，由於返回值後沒有統計，也就是說只能統計平行的調用
            if (stopWatch.isRunning()){
                stopWatch.stop();
            }
            stopWatch.start(joinPoint.getSignature().toString());
        } catch (IllegalStateException e) {
            logger.error("watch start error:",e);
        }

        Object proceed = joinPoint.proceed();

        try {
            if (stopWatch.isRunning()){
                stopWatch.stop();
            }
        } catch (IllegalStateException e) {
            logger.error("watch end error:",e);
        }

        return proceed;

    }

}

View Code

這裏有幾點問題：

1.StopWatch不能重複建立，若是想統計每次controller訪問時間，必須在訪問前初始化，訪問後廢除。

2.這裏的時間統計僅僅針對controller入口的統計，也就是說，若是別的調用了service，這個時間是不統計的，由於StopWatch沒有初始化。

3.StopWatch的prettyPrint是一個很好的東東

4.若是想要向開始那樣，徹底統計每層耗時，這個設計須要從新設計。當前有這樣的想法。controller切點初始化三個或者多個StopWatch；service、repository等分別創建切點並計時；controller執行完畢以後的切點彙總統計數據，銷燬各個StopWatch。這樣就作到了每一個層都統計了。然而問題來了，若是一個controller調用了多個service，顯然須要統計全部service耗時和單個service耗時。

Boo! Big Bug!!!

今早起來接着看，突然想起spring bean管理是單例的，並且必須是單例的纔可使用共同的成員變量，但問題來了，spring的controller是多線程的。也就是說，這個切面進入不是排隊的，第一個請求過程當中第二個請求也是能夠進來的。那麼，共享成員變量實在是愚蠢的決定。然而選擇建立一個類來管理對應一個請求的計時器也很差的，若是併發量超級大豈不是每一個人都會產生一個類？

所以，這個計時器必須是一個過程量，能夠在指定區間（即controller執行期間）生存，然後銷燬。對應的，顯然是每一個併發請求會至少產生一個類。也就是說，我須要在controller請求的時候new 一個StopWatch的id，而後在接下來的一系列調用中都使用這個id對應的計時器，最後銷燬。若是幾百萬個併發量，那麼就會產生幾百萬個類實例。懵逼。

最終選擇

經過一個實例來保存一次請求狀態太消耗性能，而若是不經過一個類實例保存狀態就沒法彙總全部的時間。因此這個方案不合適。那麼，剩下日誌和傳入數據庫。當下就先記錄日誌好了。記錄想要記錄的節點的時間：

package com.test.spring.aop.monitor;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;

/**
 * Created by miaorf on 2016/7/16.
 */
@Aspect
@Component
public class UserMonitor {

    private static Logger logger = LoggerFactory.getLogger(UserMonitor.class);

    @Pointcut("execution(* com.test.spring.aop.web.UserController.users())")
    public void controllerPerformance() {
    }

    @Pointcut("execution(* com.test.spring.aop.domain.service.impl.UserService.getAll())")
    public void servicePerformance() {
    }

    @Pointcut("execution(* com.test.spring.aop.domain.repository.impl.UserDao.getAll())")
    public void repositoryPerformance() {
    }

    @Pointcut("execution(* com.test.spring.aop.domain.repository.impl.Connector.getSthFromRemote())")
    public void connectorPerformance() {
    }


    @Around("controllerPerformance() || servicePerformance() || repositoryPerformance() || connectorPerformance()")
    public Object watchPerformance(ProceedingJoinPoint joinPoint) throws Throwable {
        Signature signature = joinPoint.getSignature();
        logger.info("=================start {}=====================",signature.getName());

        StopWatch stopWatch = new StopWatch("controller");
        try {
            if (stopWatch.isRunning()) {
                stopWatch.stop();
            }

            stopWatch.start(signature.toString());
        } catch (IllegalStateException e) {
            logger.error("watch start error:", e);
        }

        Object proceed = joinPoint.proceed();

        try {
            if (stopWatch.isRunning()) {
                stopWatch.stop();
                logger.info(stopWatch.prettyPrint()+"\n================= end {}=====================",signature.getName());
            }
        } catch (IllegalStateException e) {
            logger.error("watch end error:", e);
        }

        return proceed;
    }

}

View Code

壓力測試

1.創建test case

首先，測試controller：建立com.test.spring.aop.web.UserControllerTest

package com.test.spring.aop.web;

import com.test.spring.aop.Application;
import org.junit.Assert;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.SpringApplicationConfiguration;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;
import org.springframework.test.context.web.WebAppConfiguration;
import org.springframework.test.web.servlet.MockMvc;
import org.springframework.test.web.servlet.MvcResult;
import org.springframework.test.web.servlet.request.MockMvcRequestBuilders;
import org.springframework.test.web.servlet.result.MockMvcResultHandlers;
import org.springframework.test.web.servlet.result.MockMvcResultMatchers;
import org.springframework.test.web.servlet.setup.MockMvcBuilders;
import org.springframework.web.context.WebApplicationContext;

import static org.junit.Assert.*;

/**
 * Created by miaorf on 2016/7/17.
 */
@RunWith(SpringJUnit4ClassRunner.class)
@SpringApplicationConfiguration(Application.class)
@WebAppConfiguration
public class UserControllerTest {
    @Autowired
    private WebApplicationContext wac;
    private MockMvc mockMvc;

    @Before
    public void setUp() {
        mockMvc = MockMvcBuilders.webAppContextSetup(wac).build();
    }

    @Test
    public void testUsers() throws Exception {
        MvcResult result = mockMvc.perform(MockMvcRequestBuilders.get("/user/all"))
                .andExpect(MockMvcResultMatchers.status().isOk())
                .andExpect(MockMvcResultMatchers.jsonPath("$[0].id").value(0))
//                .andDo(MockMvcResultHandlers.print())
                .andReturn();
    }

    @Test
    public void testUsersConcurrent() throws  Exception{
        for (int i = 0; i < 10; i++) {
            new Thread(() -> {
                try {
                    mockMvc.perform(MockMvcRequestBuilders.get("/user/all")).andExpect(MockMvcResultMatchers.status().isOk());
                } catch (Exception e) {
                    e.printStackTrace();
                }
            }).run();
        }
    }

}

View Code

不知道爲啥，個人new Thread並無併發執行，而是按順序執行的。也就是說，雖然我new 10 個Thread，但仍是一個接一個的運行。

改進
因而，我想採用線程池：

 @Test
    public void testUsersConcurrent() throws  Exception{

        ThreadPoolExecutor executor = new ThreadPoolExecutor(5,10,200, TimeUnit.MILLISECONDS,new ArrayBlockingQueue<Runnable>(5));
        //不能超過15
        for (int i = 0; i < 15; i++) {
            executor.execute(()->{
                try {
                    mockMvc.perform(MockMvcRequestBuilders.get("/user/all")).andExpect(MockMvcResultMatchers.status().isOk());
                } catch (Exception e) {
                    e.printStackTrace();
                }
            });
        }

        //等待其餘線程執行,方便查看控制檯打印結果
        Thread.sleep(100000);
    }

這下就能夠看到controller是多線程併發的了，由於瞬間就打印了10條controller訪問日誌，正好是線程池的最大容量：

016-07-17 12:20:10.336  INFO 12792 --- [           main] o.s.t.web.servlet.TestDispatcherServlet  : FrameworkServlet '': initialization completed in 24 ms
2016-07-17 12:20:10.431  INFO 12792 --- [pool-1-thread-8] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.431  INFO 12792 --- [pool-1-thread-6] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.431  INFO 12792 --- [pool-1-thread-4] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.431  INFO 12792 --- [pool-1-thread-2] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.432  INFO 12792 --- [ool-1-thread-10] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.432  INFO 12792 --- [pool-1-thread-3] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.432  INFO 12792 --- [pool-1-thread-7] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.432  INFO 12792 --- [pool-1-thread-5] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.432  INFO 12792 --- [pool-1-thread-1] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:20:10.432  INFO 12792 --- [pool-1-thread-9] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================

View Code

2.採用Apache 的ab進行併發訪問

2.1下載Apache

參考：使用Apache Server 的ab進行web請求壓力測試

2.2測試

D:\Java\httpd-2.4.23-x64-vc14\Apache24\bin>ab -n 20 -c 10 localhost:8080/user/all
This is ApacheBench, Version 2.3 <$Revision: 1748469 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient).....done


Server Software:        Apache-Coyote/1.1
Server Hostname:        localhost
Server Port:            8080

Document Path:          /user/all
Document Length:        1836671 bytes

Concurrency Level:      10
Time taken for tests:   31.199 seconds
Complete requests:      20
Failed requests:        0
Total transferred:      36736380 bytes
HTML transferred:       36733420 bytes
Requests per second:    0.64 [#/sec] (mean)
Time per request:       15599.677 [ms] (mean)
Time per request:       1559.968 [ms] (mean, across all concurrent requests)
Transfer rate:          1149.88 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.4      0       1
Processing: 14785 15524 600.3  16085   16148
Waiting:    14593 15310 505.1  15781   15831
Total:      14785 15524 600.3  16085   16148

Percentage of the requests served within a certain time (ms)
  50%  16085
  66%  16090
  75%  16099
  80%  16114
  90%  16140
  95%  16148
  98%  16148
  99%  16148
 100%  16148 (longest request)

View Code

能夠看到服務端是多線程的：

2016-07-17 12:26:28.455  INFO 18580 --- [           main] com.test.spring.aop.Application          : Started Application in 8.37 seconds (JVM running for 9.23)
2016-07-17 12:26:40.966  INFO 18580 --- [nio-8080-exec-9] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring FrameworkServlet 'dispatcherServlet'
2016-07-17 12:26:40.966  INFO 18580 --- [nio-8080-exec-9] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started
2016-07-17 12:26:40.992  INFO 18580 --- [nio-8080-exec-9] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization completed in 25 ms
2016-07-17 12:26:41.049  INFO 18580 --- [nio-8080-exec-5] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.049  INFO 18580 --- [io-8080-exec-10] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.049  INFO 18580 --- [nio-8080-exec-8] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.050  INFO 18580 --- [nio-8080-exec-7] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.050  INFO 18580 --- [nio-8080-exec-2] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.050  INFO 18580 --- [nio-8080-exec-1] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.050  INFO 18580 --- [nio-8080-exec-3] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.050  INFO 18580 --- [nio-8080-exec-4] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.051  INFO 18580 --- [nio-8080-exec-6] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:41.051  INFO 18580 --- [nio-8080-exec-9] com.test.spring.aop.monitor.UserMonitor  : =================start UserController.users()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [nio-8080-exec-1] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [nio-8080-exec-6] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [nio-8080-exec-9] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [io-8080-exec-10] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [nio-8080-exec-3] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [nio-8080-exec-2] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [nio-8080-exec-4] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.061  INFO 18580 --- [nio-8080-exec-8] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.062  INFO 18580 --- [nio-8080-exec-5] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:51.062  INFO 18580 --- [nio-8080-exec-7] com.test.spring.aop.monitor.UserMonitor  : =================start IUserService.getAll()=====================
2016-07-17 12:26:52.062  INFO 18580 --- [nio-8080-exec-9] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.062  INFO 18580 --- [nio-8080-exec-6] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.062  INFO 18580 --- [nio-8080-exec-1] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.063  INFO 18580 --- [io-8080-exec-10] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.063  INFO 18580 --- [nio-8080-exec-3] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.063  INFO 18580 --- [nio-8080-exec-2] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.063  INFO 18580 --- [nio-8080-exec-8] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.063  INFO 18580 --- [nio-8080-exec-4] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.063  INFO 18580 --- [nio-8080-exec-5] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:52.063  INFO 18580 --- [nio-8080-exec-7] com.test.spring.aop.monitor.UserMonitor  : =================start IConnector.getSthFromRemote()=====================
2016-07-17 12:26:54.063  INFO 18580 --- [nio-8080-exec-6] com.test.spring.aop.monitor.UserMonitor  : StopWatch 'controller': running time (millis) = 2000
-----------------------------------------
ms     %     Task name
-----------------------------------------
02000  100%  Object com.test.spring.aop.domain.repository.IConnector.getSthFromRemote()

================= end IConnector.getSthFromRemote()=====================
2016-07-17 12:26:54.063  INFO 18580 --- [nio-8080-exec-9] com.test.spring.aop.monitor.UserMonitor  : StopWatch 'controller': running time (millis) = 2001
-----------------------------------------
ms     %     Task name
-----------------------------------------
02001  100%  Object com.test.spring.aop.domain.repository.IConnector.getSthFromRemote()

================= end IConnector.getSthFromRemote()=====================
2016-07-17 12:26:54.063  INFO 18580 --- [nio-8080-exec-3] com.test.spring.aop.monitor.UserMonitor  : StopWatch 'controller': running time (millis) = 2000
-----------------------------------------
ms     %     Task name
-----------------------------------------
02000  100%  Object com.test.spring.aop.domain.repository.IConnector.getSthFromRemote()

================= end IConnector.getSthFromRemote()=====================
2016-07-17 12:26:54.063  INFO 18580 --- [nio-8080-exec-1] com.test.spring.aop.monitor.UserMonitor  : StopWatch 'controller': running time (millis) = 2000
-----------------------------------------
ms     %     Task name
-----------------------------------------
02000  100%  Object com.test.spring.aop.domain.repository.IConnector.getSthFromRemote()

================= end IConnector.getSthFromRemote()=====================
2016-07-17 12:26:54.063  INFO 18580 --- [io-8080-exec-10] com.test.spring.aop.monitor.UserMonitor  : StopWatch 'controller': running time (millis) = 2000
-----------------------------------------
ms     %     Task name
-----------------------------------------
02000  100%  Object com.test.spring.aop.domain.repository.IConnector.getSthFromRemote()

================= end IConnector.getSthFromRemote()=====================
2016-07-17 12:26:54.064  INFO 18580 --- [nio-8080-exec-4] com.test.spring.aop.monitor.UserMonitor  : StopWatch 'controller': running time (millis) = 2001
-----------------------------------------
ms     %     Task name
-----------------------------------------
02001  100%  Object com.test.spring.aop.domain.repository.IConnector.getSthFromRemote()