前段时间架构让我弄日志埋点，因为其他工作不断延期，而且到现在也没给明确的需求，这里自己手写一套简单的日志埋点：
第一步：引入依赖
<!--aop--> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-aop</artifactId> </dependency> <!--log4j--> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>2.3</version> </dependency> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-log4j12</artifactId> <version>1.7.25</version> </dependency>
第二步：因为公司有自己的日志配置，这里我简单配置一条凑合用就行，在application.properties配置：
#日志文件路径 默认生成文件名：spring.log 为了简单便于学习这里我使用默认的 logging.path=F:/Log4j
第三步：自定义注解：
package com.javaliao.portal.annotations; import org.springframework.web.bind.annotation.ResponseBody; import java.lang.annotation.*; /** * app controller 统一包装注解类 */ @Target({ElementType.PARAMETER, ElementType.METHOD})//作用在参数和方法上 @Retention(RetentionPolicy.RUNTIME)//运行时注解 @Documented//表明这个注解应该被 javadoc工具记录 @ResponseBody//响应时转JSON格式 public @interface AppController { /** * 业务描述 * @return */ String description() default ""; /** * 是否打日志 默认打 */ boolean isLog() default true; }
第四步：拦截用户请求
package com.javaliao.portal.aspect; import com.alibaba.fastjson.JSON; import com.javaliao.portal.annotations.AppController; import com.javaliao.portal.common.CommonResult; import com.javaliao.portal.model.TbLogVisit; import com.javaliao.portal.service.ActionService; import com.javaliao.portal.util.CollectionHelp; import com.javaliao.portal.util.TimeUtils; import org.aspectj.lang.JoinPoint; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.*; import org.aspectj.lang.reflect.MethodSignature; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.stereotype.Component; import org.springframework.web.context.request.RequestContextHolder; import org.springframework.web.context.request.ServletRequestAttributes; import javax.annotation.Resource; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpSession; import java.lang.reflect.Method; import java.net.InetAddress; import java.util.*; import java.util.concurrent.atomic.AtomicLong; @Component @Aspect @SuppressWarnings("all") //@SuppressWarnings("all")抑制所有警告.@SuppressWarnings注解主要用在取消一些编译器产生的警告对代码左侧行列的遮挡，有时候这会挡住我们断点调试时打的断点 public class AppControllerAspect { //注入Service用于把日志保存数据库，实际项目入库采用队列做异步 @Resource private ActionService actionService; //日志工厂获取日志对象 static Logger logger = LoggerFactory.getLogger(AppControllerAspect.class); /** * ThreadLocal多线程环境下，创建多个副本，各自执行，互不干扰 */ //startTime存放开始时间 ThreadLocal<Map<String, Long >> startTime = new ThreadLocal<>(); //count存放方法被调用的次数O 使用volatile利用它的三大特性：保证可见性（遵守JMM的可见性），不保证原子性，禁止指令重排 volatile ThreadLocal<Map<String, Long>> count = new ThreadLocal<>(); //timeConsuming存放方法总耗时 ThreadLocal<Map<String, Long >> timeConsuming = new ThreadLocal<>(); //fromType存放渠道 ThreadLocal<Map<String, String >> fromType = new ThreadLocal<>(); //tbLogVisit日志访问对象 ThreadLocal<TbLogVisit> tbLogVisit = new ThreadLocal<>(); //Controller层切点 @Pointcut("@annotation(com.javaliao.portal.annotations.AppController)") public void controllerAspectse() { } //前置通知 用于拦截Controller层记录用户的操作 @Before("controllerAspectse()") public void before(JoinPoint pjp) { //初始化 TbLogVisit tbLogVisit = this.tbLogVisit.get(); tbLogVisit = new TbLogVisit(); Map<String, Long> countMap = this.count.get(); countMap = new HashMap<>(); this.count.set(countMap); Map<String, Long> timeConsumingMap = this.timeConsuming.get(); timeConsumingMap = new HashMap<>(); this.timeConsuming.set(timeConsumingMap); Map<String, String> fromTypeMap = this.fromType.get(); fromTypeMap = new HashMap<>(); this.fromType.set(fromTypeMap); Map<String, Long> map = new HashMap<>(); map.put("startTime",System.currentTimeMillis()); this.startTime.set(map); logger.info("==============前置通知开始:记录用户的操作=============="); String currentTime = TimeUtils.getCurrentTime("YYYY-MM-dd HH:mm:ss"); logger.info("请求开始时间:" + currentTime); tbLogVisit.setVisitStartTime(new Date()); String resultString = ""; // 是否打日志 默认打 boolean isLog = true; try { MethodSignature signature = (MethodSignature) pjp.getSignature(); AppController appController = signature.getMethod().getAnnotation(AppController.class); //是否开启日志打印 isLog = appController.isLog(); if(isLog){ //开始打印日志 HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest(); HttpSession session = request.getSession(); String api = pjp.getTarget().getClass().getName() + "." + pjp.getSignature().getName(); logger.info("请求API：" + api); tbLogVisit.setVisitApi(api); String methodDescription = getControllerMethodDescription(pjp); logger.info("方法描述：" + methodDescription); tbLogVisit.setVisitDescription(methodDescription); String ipAddress = InetAddress.getLocalHost().toString().substring(InetAddress.getLocalHost().toString().lastIndexOf("/") + 1); logger.info("请求ip："+ ipAddress); tbLogVisit.setVisitIpAddress(ipAddress); String hostName = InetAddress.getLocalHost().getHostName(); logger.info("机器名：" + hostName); tbLogVisit.setVisitHostName(hostName); Enumeration<?> enu = request.getParameterNames(); String params = "{"; while (enu.hasMoreElements()) { String paraName = (String) enu.nextElement(); params += "\"" + paraName + "\":\"" + request.getParameter(paraName) + "\","; } String methodParams = params + "}"; String substring = methodParams.substring(0, methodParams.length() - 2); substring = substring + "}"; logger.info("方法参数：" + substring); tbLogVisit.setVisitParams(substring); StringBuffer url = request.getRequestURL(); logger.info("URL：" + url); tbLogVisit.setVisitUrl(String.valueOf(url)); } } catch (Exception e) { StackTraceElement stackTraceElement2 = e.getStackTrace()[2]; String reason = "异常：【"+ "类名："+stackTraceElement2.getClassName()+";"+ "文件："+stackTraceElement2.getFileName()+";"+"行："+ stackTraceElement2.getLineNumber()+";"+"方法：" +stackTraceElement2.getMethodName() + "】"; //记录本地异常日志 logger.error("==============前置通知异常:记录访问异常信息=============="); String message = e.getMessage() + "|" + reason; logger.error("异常信息：",message); tbLogVisit.setVisitThrowingErro(message); tbLogVisit.setVisitResult("请求发生异常，异常信息：" + message); }finally { this.tbLogVisit.set(tbLogVisit); } } @Around("controllerAspectse()") public Object around(ProceedingJoinPoint pjp)throws Throwable { String result = JSON.toJSONString(pjp.proceed()); logger.info("请求结果：" + result); TbLogVisit tbLogVisit = this.tbLogVisit.get(); tbLogVisit.setVisitResult(result); this.tbLogVisit.set(tbLogVisit); return CommonResult.success(""); } /** * 对Controller下面的方法执行后进行切入，统计方法执行的次数和耗时情况 * 注意，这里的执行方法统计的数据不止包含Controller下面的方法，也包括环绕切入的所有方法的统计信息 * @param jp */ @AfterReturning("controllerAspectse()") public void afterMehhod(JoinPoint jp) { logger.info("==============方法执行完成=============="); TbLogVisit tbLogVisit = this.tbLogVisit.get(); try { //获取方法名 String methodName = jp.getSignature().getName(); //开始统计数量与耗时 if(count.get().get(methodName) == null){ //第一次赋值为0 count.get().put(methodName,0L); } //使用原子整型进行增值 AtomicLong atomicInteger = new AtomicLong(count.get().get(methodName)); //加一 这里暂时不解决ABA问题，仅保证原子性 解决了volatile不保证原子性的问题 getAndIncrement()先返回再加1,incrementAndGet()先加1再返回 long increment = atomicInteger.incrementAndGet(); //然后增加新值 count.get().replace(methodName,increment); Long end = System.currentTimeMillis(); Long total = end - startTime.get().get("startTime"); logger.info("执行总耗时为：" +total); if(timeConsuming.get().containsKey(methodName)){ timeConsuming.get().replace(methodName, total); }else { timeConsuming.get().put(methodName, (total)); } tbLogVisit = this.tbLogVisit.get(); tbLogVisit.setVisitTimeConsuming(String.valueOf(total)); String endTime = TimeUtils.getCurrentTime("YYYY-MM-dd HH:mm:ss"); logger.info("请求结束时间:" + endTime); tbLogVisit.setVisitEndTime(new Date()); /** * 从原来的map中将最后的连接点方法给移除了，替换成最终的，避免连接点方法多次进行叠加计算， * 由于原来的map受ThreadLocal的保护，这里不支持remove，因此，需要单开一个map进行数据交接 */ //重新new一个map Map<String, Long> map = new HashMap<>(); for(Map.Entry<String, Long> entry:timeConsuming.get().entrySet()){ if(entry.getKey().equals(methodName)){ map.put(methodName, total); }else{ map.put(entry.getKey(), entry.getValue()); } } for (Map.Entry<String, Long> entry :count.get().entrySet()) { for(Map.Entry<String, Long> entry2 :map.entrySet()){ if(entry.getKey().equals(entry2.getKey())){ Long num = entry.getValue(); logger.info("调用次数：" + num); tbLogVisit.setVisitNum(num); } } } //这里的渠道暂时写死 Map<String, String> stringMap = fromType.get(); Map<String, String> fromMap ; if(CollectionHelp.isMapNotEmpty(stringMap)){ fromMap = stringMap; }else { fromMap = new HashMap<>(); fromMap.put(methodName,"个人开发电商平台"); } String channel = fromMap.get(methodName); logger.info("渠道：" + channel); tbLogVisit.setVisitChannel(channel); } catch (Exception e) { StackTraceElement stackTraceElement2 = e.getStackTrace()[2]; String reason = "异常：【"+ "类名："+stackTraceElement2.getClassName()+";"+ "文件："+stackTraceElement2.getFileName()+";"+"行："+ stackTraceElement2.getLineNumber()+";"+"方法：" +stackTraceElement2.getMethodName() + "】"; //记录本地异常日志 logger.error("==============通知异常:记录访问异常信息=============="); String message = e.getMessage() + "|" + reason; logger.error("异常信息：",message); tbLogVisit.setVisitThrowingErro(message); tbLogVisit.setVisitResult("请求发生异常！！！"); } finally { this.tbLogVisit.set(tbLogVisit); //添加日志信息入库 actionService.insertLogVisit(this.tbLogVisit.get()); } } /** * 获取注解中对方法的描述信息 用于Controller层注解 */ public static String getControllerMethodDescription(JoinPoint joinPoint) throws Exception { String targetName = joinPoint.getTarget().getClass().getName(); String methodName = joinPoint.getSignature().getName();//目标方法名 Object[] arguments = joinPoint.getArgs(); Class targetClass = Class.forName(targetName); Method[] methods = targetClass.getMethods(); String description = ""; for (Method method:methods) { if (method.getName().equals(methodName)){ Class[] clazzs = method.getParameterTypes(); if (clazzs.length==arguments.length){ description = method.getAnnotation(AppController.class).description(); break; } } } return description; } }
第五步：业务层发消息：
package com.javaliao.portal.service.impl; import com.javaliao.portal.mapper.TbLogVisitMapper; import com.javaliao.portal.model.TbLogVisit; import com.javaliao.portal.service.ActionService; import com.javaliao.portal.util.ActiveMQUtil; import net.sf.json.JSONObject; import org.apache.activemq.command.ActiveMQMapMessage; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Service; import javax.jms.*; @Service public class ActionServiceImpl implements ActionService { @Autowired TbLogVisitMapper tbLogVisitMapper; @Autowired ActiveMQUtil activeMQUtil; @Override public void insertLogVisit(TbLogVisit tbLogVisit) { try { // 连接消息服务器 Connection connection = activeMQUtil.getConnection(); connection.start(); //第一个值表示是否使用事务，如果选择true，第二个值相当于选择0 Session session = connection.createSession(true, Session.SESSION_TRANSACTED); // 发送消息 Queue testqueue = session.createQueue("LOG_VISIT_QUEUE"); MessageProducer producer = session.createProducer(testqueue); MapMessage mapMessage=new ActiveMQMapMessage(); String toString = JSONObject.fromObject(tbLogVisit).toString(); mapMessage.setString("tbLogVisit",toString); producer.setDeliveryMode(DeliveryMode.PERSISTENT); producer.send(mapMessage); session.commit();// 事务型消息，必须提交后才生效 connection.close(); } catch (JMSException e) { e.printStackTrace(); } } }
第六步：接收消息执行添加业务：
package com.javaliao.portal.listener; import com.javaliao.portal.log4j.BaseLogger; import com.javaliao.portal.model.TbLogVisit; import com.javaliao.portal.service.ActionService; import net.sf.json.JSONObject; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.jms.annotation.JmsListener; import org.springframework.stereotype.Component; import javax.jms.JMSException; import javax.jms.MapMessage; @Component public class LogVisitListener { @Autowired ActionService actionService; @JmsListener(containerFactory = "jmsQueueListener" ,destination = "LOG_VISIT_QUEUE") public void consumeLogResult(MapMessage mapMessage){ try { String object = mapMessage.getString("tbLogVisit"); JSONObject jsonObject = new JSONObject().fromObject(object); TbLogVisit logVisit = (TbLogVisit) JSONObject.toBean(jsonObject, TbLogVisit.class); int count = actionService.insertLog(logVisit); if(count < 1){ BaseLogger.info("日志更新失败"); } } catch (JMSException e) { e.printStackTrace(); } } }
执行业务：
package com.javaliao.portal.service.impl; import com.javaliao.portal.mapper.TbLogVisitMapper; import com.javaliao.portal.model.TbLogVisit; import com.javaliao.portal.model.TbLogVisitExample; import com.javaliao.portal.service.ActionService; import com.javaliao.portal.util.ActiveMQUtil; import com.javaliao.portal.util.CollectionHelp; import com.javaliao.portal.util.NumberUtils; import net.sf.json.JSONObject; import org.apache.activemq.command.ActiveMQMapMessage; import org.apache.commons.lang3.StringUtils; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Service; import javax.jms.*; import java.util.Date; import java.util.List; @Service public class ActionServiceImpl implements ActionService { @Autowired TbLogVisitMapper tbLogVisitMapper; //这里去掉了之前发消息的代码 /** * 添加日志信息入库 * @param tbLogVisit * @return */ @Override public int insertLog(TbLogVisit tbLogVisit) { tbLogVisit.setUpdateTime(new Date()); int count = 0; //如果有异常直接添加 if(StringUtils.isNoneEmpty(tbLogVisit.getVisitThrowingErro())){ tbLogVisit.setCreateTime(new Date()); count = tbLogVisitMapper.insert(tbLogVisit); }else { String visitIpAddress = tbLogVisit.getVisitIpAddress(); String visitApi = tbLogVisit.getVisitApi(); TbLogVisitExample tbLogVisitExample = new TbLogVisitExample(); TbLogVisitExample.Criteria criteria = tbLogVisitExample.createCriteria(); criteria.andVisitIpAddressEqualTo(visitIpAddress); criteria.andVisitApiEqualTo(visitApi); List<TbLogVisit> tbLogVisits = tbLogVisitMapper.selectByExample(tbLogVisitExample); if(CollectionHelp.isNotEmpty(tbLogVisits)){ Long nums = 0L; Double sums = 0D; for (TbLogVisit logVisit : tbLogVisits) { //统计调用次数 Long visitNum = logVisit.getVisitNum(); nums = tbLogVisit.getVisitNum() + visitNum; //统计耗时 Double visitTimeConsumingData = NumberUtils.Double(logVisit.getVisitTimeConsuming()); Double visitTimeConsumingParam = NumberUtils.Double(tbLogVisit.getVisitTimeConsuming()); Double sum = visitTimeConsumingData + visitTimeConsumingParam; sums = sums + sum; } Double numDouble = NumberUtils.Double(String.valueOf(nums)); //统计平均耗时 Double avg = sums / numDouble; tbLogVisit.setVisitTimeConsuming(avg.toString()); tbLogVisit.setVisitNum(nums); count = tbLogVisitMapper.updateByExample(tbLogVisit,tbLogVisitExample); }else { tbLogVisit.setCreateTime(new Date()); count = tbLogVisitMapper.insert(tbLogVisit); } } return count; } }
这里提供我写的项目地址：https://github.com/javaliao/personalmall
一开始没有设计好，后面强迫改动，导致访客的开始时间和结束时间都是最近一次的，不过我把每次请求的耗时改为平均耗时，勉强达到效果（不过有些请求异常的耗时时间长的就比较影响耗时统计了，唉不说了，最开始没有设计好，也算勉强了），效率也不算太差，不会太影响性能，
