aop统计请求数量_Spring-AOP实践 - 统计访问时间

公司的项目有的页面超级慢,20s以上,不知道用户会不会疯掉,于是老大说这个页面要性能优化。于是,首先就要搞清楚究竟是哪一步耗时太多。

我采用spring aop来统计各个阶段的用时,其中计时器工具为StopWatch。

文章结构:

其中,遇到的问题:

1.少包aspectjweaver

添加依赖后才可以使用@Aspect

2.环绕通知加入多个point

刚开使用&&连接多个point,傻傻的看不到调用,忽然看到要用||才对

3.监听时间工具StopWatch每次只能启动一个,一定要关闭后才能启动下一个。

而我想要测试controller->service->repository各个阶段用时显然很不适应。因为使用同一个stopwatch对象来保存时间,而stopwatch每次只能记录一个时间段作为总时间的一部分,不存在时间嵌套关系(这个以后可以考虑想想别的方案)。controller开始后执行部分验证逻辑或是其他,然后调用service,这时候service启动定时会失败,因为controller的计时器还没关,因此需要先关掉controller的计时器。这样会导致controller的计时部分仅仅是调用service之前的时间,service返回值之后,controller再进行某些处理的时间并没有统计。显然,我需要一个卡表的时间统计设计,即进入controller开始计时,调用service后开始service计时,以此类推,最后获得controller总时间Tc,service总时间Ts,repository总时间Tr.所以时间统计应该如图1:

                

图一                                                                 图二

这样的话,我应该分别获得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依赖:

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">

4.0.0

com.test

spring-aop

1.0-SNAPSHOT

org.springframework.boot

spring-boot-dependencies

1.3.5.RELEASE

pom

import

org.springframework.boot

spring-boot-starter-aop

org.springframework.boot

spring-boot-starter-web

org.springframework.boot

spring-boot-starter-test

test

org.assertj

assertj-core-java8

1.0.0m1

org.springframework.boot

spring-boot-maven-plugin

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()即可。

命令行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

packagecom.test.spring.aop;importorg.junit.After;importorg.junit.Before;importorg.junit.Rule;importorg.junit.Test;importorg.springframework.boot.test.OutputCapture;import staticorg.assertj.core.api.Assertions.assertThat;/*** Created by miaorf on 2016/7/16.*/

public classApplicationTest {

@Rulepublic OutputCapture outputCapture = newOutputCapture();privateString profiles;

@Beforepublic void init() throwsException {this.profiles = System.getProperty("spring.profiles.active");

}

@Afterpublic void tearDown() throwsException {if (this.profiles != null){

System.setProperty("spring.profiles.active",this.profiles);

}else{

System.out.println("spring.profiles.active");

}

}

@Testpublic void testDefaultSettings() throwsException{

Application.main(new String[0]);

String s= this.outputCapture.toString();

assertThat(s).contains("Hi Ryan");

}

@Testpublic void testCommandLineOverrides() throwsException {

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

packagecom.test.spring.aop.monitor;importorg.aspectj.lang.ProceedingJoinPoint;import org.aspectj.lang.annotation.*;importorg.slf4j.Logger;importorg.slf4j.LoggerFactory;importorg.springframework.stereotype.Component;importorg.springframework.util.StopWatch;/*** Created by miaorf on 2016/7/16.*/@Aspect

@Componentpublic classServiceMonitor {private static Logger logger = LoggerFactory.getLogger(ServiceMonitor.class);

StopWatch stopWatch= new StopWatch("performance");/*** define point*/@Pointcut("execution(* com.test.spring.aop..*Service.*(..))")public voidperformance(){}//@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);//}

/*** 必须要返回,不然后面收不到

*@parampoint

*@return

*/@Around("performance()")publicObject watchPerformance(ProceedingJoinPoint point){

System.out.println("The service start:");

stopWatch.start(point.getSignature().toString());try{returnpoint.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:

packagecom.test.spring.aop.web;importcom.test.spring.aop.domain.entiry.User;importcom.test.spring.aop.domain.service.IUserService;importorg.springframework.beans.factory.annotation.Autowired;importorg.springframework.stereotype.Controller;importorg.springframework.web.bind.annotation.RequestMapping;importorg.springframework.web.bind.annotation.ResponseBody;importjava.util.List;/*** Created by miaorf on 2016/7/16.*/@Controller

@RequestMapping("/user")public classUserController {

@AutowiredprivateIUserService userService;

@ResponseBody

@RequestMapping("/all")public Listusers(){try {Thread.sleep(1000);} catch(InterruptedException e) {e.printStackTrace();}

List all =userService.getAll();returnall;

}

}

View Code

3.2发现需要一个service

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

packagecom.test.spring.aop.domain.service;importcom.test.spring.aop.domain.entiry.User;importjava.util.List;/*** Created by miaorf on 2016/7/16.*/

public interfaceIUserService {

ListgetAll();

}

View Code

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

packagecom.test.spring.aop.domain.service.impl;importcom.test.spring.aop.domain.entiry.User;importcom.test.spring.aop.domain.repository.IConnector;importcom.test.spring.aop.domain.repository.IUserDao;importcom.test.spring.aop.domain.service.IUserService;importorg.springframework.beans.factory.annotation.Autowired;importorg.springframework.stereotype.Service;importjava.util.List;/*** Created by miaorf on 2016/7/16.*/@Servicepublic class UserService implementsIUserService {

@AutowiredprivateIUserDao userDao;

@AutowiredprivateIConnector connector;public ListgetAll() {try {Thread.sleep(1000);} catch(InterruptedException e) {e.printStackTrace();}

connector.getSthFromRemote();returnuserDao.getAll();

}

}

View Code

3.3发现需要一个repository

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

packagecom.test.spring.aop.domain.repository;importcom.test.spring.aop.domain.entiry.User;importjava.util.List;/*** Created by miaorf on 2016/7/16.*/

public interfaceIUserDao {

ListgetAll();

}

View Code

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

packagecom.test.spring.aop.domain.repository.impl;importcom.test.spring.aop.domain.entiry.User;importcom.test.spring.aop.domain.repository.IUserDao;importorg.springframework.stereotype.Repository;importjava.util.ArrayList;importjava.util.List;/*** Created by miaorf on 2016/7/16.*/@Repositorypublic class UserDao implementsIUserDao {public ListgetAll() {//mock data

List list = new ArrayList(10000);for (int i = 0; i < 10000; i++) {

list.add(new User(i,"name_"+i,getRondomString(6),i,i%2,getRondomString(100)));

}returnlist;

}private String getRondomString(intlength){

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= newStringBuffer();for (int i = 0; i < length; i++) {int random = (int) (Math.random() * 10000 + 1);

result.append(arr[random%arr.length]);

}returnresult.toString();

}

}

View Code

3.3.1临时添加一个远程调用

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

packagecom.test.spring.aop.domain.repository;/*** Created by miaorf on 2016/7/16.*/

public interfaceIConnector {

Object getSthFromRemote();

}

View Code

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

packagecom.test.spring.aop.domain.repository.impl;importcom.test.spring.aop.domain.repository.IConnector;importorg.springframework.stereotype.Component;/*** Created by miaorf on 2016/7/16.*/@Componentpublic class Connector implementsIConnector {publicObject 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

packagecom.test.spring.aop.domain.entiry;/*** Created by miaorf on 2016/7/16.*/

public classUser {

Integer id;

String username;

String password;

Integer age;

Integer sex;

String info;publicUser() {

}publicUser(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;

}publicInteger getId() {returnid;

}public voidsetId(Integer id) {this.id =id;

}publicString getUsername() {returnusername;

}public voidsetUsername(String username) {this.username =username;

}publicString getPassword() {returnpassword;

}public voidsetPassword(String password) {this.password =password;

}publicInteger getAge() {returnage;

}public voidsetAge(Integer age) {this.age =age;

}publicInteger getSex() {returnsex;

}public voidsetSex(Integer sex) {this.sex =sex;

}publicString getInfo() {returninfo;

}public voidsetInfo(String info) {this.info =info;

}

@OverridepublicString 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

packagecom.test.spring.aop.monitor;importorg.aspectj.lang.ProceedingJoinPoint;import org.aspectj.lang.annotation.*;importorg.slf4j.Logger;importorg.slf4j.LoggerFactory;importorg.springframework.stereotype.Component;importorg.springframework.util.StopWatch;/*** Created by miaorf on 2016/7/16.*/@Aspect

@Componentpublic classUserMonitor {private static Logger logger = LoggerFactory.getLogger(UserMonitor.class);

StopWatch stopWatch;

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

}

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

}

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

}

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

}

@Before("controllerPerformance()")public voidstartWatch() {

stopWatch= new StopWatch("controller");

}

@After("controllerPerformance()")public voidendWatch() {

logger.info(stopWatch.prettyPrint());

stopWatch= null;

}

@Around("servicePerformance() || repositoryPerformance() || connectorPerformance()")public Object watchPerformance(ProceedingJoinPoint joinPoint) throwsThrowable {

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);

}returnproceed;

}

}

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对应的计时器,最后销毁。如果几百万个并发量,那么就会产生几百万个类实例。懵逼。

最终选择

通过一个实例来保存一次请求状态太消耗性能,而如果不通过一个类实例保存状态就无法汇总所有的时间。所以这个方案不合适。那么,剩下日志和传入数据库。当下就先记录日志好了。记录想要记录的节点的时间:

packagecom.test.spring.aop.monitor;importorg.aspectj.lang.ProceedingJoinPoint;importorg.aspectj.lang.Signature;importorg.aspectj.lang.annotation.Around;importorg.aspectj.lang.annotation.Aspect;importorg.aspectj.lang.annotation.Pointcut;importorg.slf4j.Logger;importorg.slf4j.LoggerFactory;importorg.springframework.stereotype.Component;importorg.springframework.util.StopWatch;/*** Created by miaorf on 2016/7/16.*/@Aspect

@Componentpublic classUserMonitor {private static Logger logger = LoggerFactory.getLogger(UserMonitor.class);

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

}

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

}

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

}

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

}

@Around("controllerPerformance() || servicePerformance() || repositoryPerformance() || connectorPerformance()")public Object watchPerformance(ProceedingJoinPoint joinPoint) throwsThrowable {

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);

}returnproceed;

}

}

View Code

压力测试

1.建立test case

首先,测试controller:创建com.test.spring.aop.web.UserControllerTest

packagecom.test.spring.aop.web;importcom.test.spring.aop.Application;importorg.junit.Assert;importorg.junit.Before;importorg.junit.Test;importorg.junit.runner.RunWith;importorg.springframework.beans.factory.annotation.Autowired;importorg.springframework.boot.test.SpringApplicationConfiguration;importorg.springframework.test.context.junit4.SpringJUnit4ClassRunner;importorg.springframework.test.context.web.WebAppConfiguration;importorg.springframework.test.web.servlet.MockMvc;importorg.springframework.test.web.servlet.MvcResult;importorg.springframework.test.web.servlet.request.MockMvcRequestBuilders;importorg.springframework.test.web.servlet.result.MockMvcResultHandlers;importorg.springframework.test.web.servlet.result.MockMvcResultMatchers;importorg.springframework.test.web.servlet.setup.MockMvcBuilders;importorg.springframework.web.context.WebApplicationContext;import static org.junit.Assert.*;/*** Created by miaorf on 2016/7/17.*/@RunWith(SpringJUnit4ClassRunner.class)

@SpringApplicationConfiguration(Application.class)

@WebAppConfigurationpublic classUserControllerTest {

@AutowiredprivateWebApplicationContext wac;privateMockMvc mockMvc;

@Beforepublic voidsetUp() {

mockMvc=MockMvcBuilders.webAppContextSetup(wac).build();

}

@Testpublic void testUsers() throwsException {

MvcResult result= mockMvc.perform(MockMvcRequestBuilders.get("/user/all"))

.andExpect(MockMvcResultMatchers.status().isOk())

.andExpect(MockMvcResultMatchers.jsonPath("$[0].id").value(0))//.andDo(MockMvcResultHandlers.print())

.andReturn();

}

@Testpublic void testUsersConcurrent() throwsException{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(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 24ms2016-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

2.2测试

D:\Java\httpd-2.4.23-x64-vc14\Apache24\bin>ab -n 20 -c 10 localhost:8080/user/all

This is ApacheBench, Version2.3 Copyright1996 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.1Server Hostname: localhost

Server Port:8080Document Path:/user/all

Document Length:1836671bytes

Concurrency Level:10Time takenfor tests: 31.199seconds

Complete requests:20Failed requests:0Total transferred:36736380bytes

HTML transferred:36733420bytes

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 1Processing:14785 15524 600.3 16085 16148Waiting:14593 15310 505.1 15781 15831Total:14785 15524 600.3 16085 16148Percentage 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 started2016-07-17 12:26:40.992 INFO 18580 --- [nio-8080-exec-9] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization completed in 25ms2016-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()

View Code

项目源码:https://github.com/chenxing12/spring-aop

  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值