专栏首页中间件兴趣圈源码分析Dubbo服务调用日志(accesslog参数)实现原理

源码分析Dubbo服务调用日志(accesslog参数)实现原理

微信公众号:[中间件兴趣圈] 作者简介:《RocketMQ技术内幕》

谈到服务调用日志,大家恐怕第一想到就是如果开启了这个参数,会影响性能。那真实的情况是怎么样了?性能损耗到底有多大呢?在实践中我们如何使用该功能呢?本文将详细分析Dubbo accesslog实现原理。

AccessLogFilter概述

  • 过滤器作用 记录调用日志。
  • 使用场景 记录服务提供者端调用日志。
  • 阻断条件 非阻断过滤器。 接下来源码分析accesslog参数的实现原理。

核心字段说明

  • LOG_MAX_BUFFER:积累最大的日志容量,默认为5000条,如果积压在队列中的待处理日志超过该值,则直接丢弃。
  • LOG_OUTPUT_INTERVAL:日志写出的调度频率,默认为5s。
  • ConcurrentMap< String, Set< String>> logQueue:日志容器。
  • ScheduledExecutorService logScheduled:写出日志调度器,默认为2个线程,线程名称为:Dubbo-Access-Log。

invoke方法源码分析

AccessLogFilter#invoke

 1public Result invoke(Invoker<?> invoker, Invocation inv) throws RpcException {
 2        try {
 3            String accesslog = invoker.getUrl().getParameter(Constants.ACCESS_LOG_KEY);    
 4            if (ConfigUtils.isNotEmpty(accesslog)) {    // @1                                                       
 5                RpcContext context = RpcContext.getContext();
 6                String serviceName = invoker.getInterface().getName();
 7                String version = invoker.getUrl().getParameter(Constants.VERSION_KEY);
 8                String group = invoker.getUrl().getParameter(Constants.GROUP_KEY);
 9                StringBuilder sn = new StringBuilder();         // @2 start
10                sn.append("[").append(new SimpleDateFormat(MESSAGE_DATE_FORMAT).format(new Date())).append("] 
11                       ").append(context.getRemoteHost()).append(":").append(context.getRemotePort())
12                        .append(" -> ").append(context.getLocalHost()).append(":").append(context.getLocalPort())
13                        .append(" - ");
14                if (null != group && group.length() > 0) {
15                    sn.append(group).append("/");
16                }
17                sn.append(serviceName);
18                if (null != version && version.length() > 0) {
19                    sn.append(":").append(version);
20                }
21                sn.append(" ");
22                sn.append(inv.getMethodName());
23                sn.append("(");
24                Class<?>[] types = inv.getParameterTypes();
25                if (types != null && types.length > 0) {
26                    boolean first = true;
27                    for (Class<?> type : types) {
28                        if (first) {
29                            first = false;
30                        } else {
31                            sn.append(",");
32                        }
33                        sn.append(type.getName());
34                    }
35                }
36                sn.append(") ");
37                Object[] args = inv.getArguments();
38                if (args != null && args.length > 0) {
39                    sn.append(JSON.toJSONString(args));
40                }
41                String msg = sn.toString();
42                if (ConfigUtils.isDefault(accesslog)) {         // @2
43                    LoggerFactory.getLogger(ACCESS_LOG_KEY + "." + invoker.getInterface().getName()).info(msg);
44                } else {
45                    log(accesslog, msg);                              // @3
46                }
47            }
48        } catch (Throwable t) {
49            logger.warn("Exception in AcessLogFilter of service(" + invoker + " -> " + inv + ")", t);
50        }
51        return invoker.invoke(inv);                                 // @4
52    }
53

代码@1:首先从服务提供者URL中获取accesslog参数,如果存在该参数并且不为空,则进入服务调用日志,如果未配置,则直接进入下一个过滤器。

代码@2:组装服务调用日志,其内容: [服务调用时间,精确到时分秒] + 消费者IP:消费者PORT + --> 服务提供者IP:服务提供者端口 + "服务提供者group/"(可选) + serviceName(interface name) + ":version"(可选) + methodName( + 参数类型列表)+ 参数值(json格式的字符串) 。

代码@3:如果accesslog="true",则使用info级别的日志输出;如果是配置的是日志路径的话,则异步写入文件。 接下来分析一下log方法,写入日志文件的具体实现:

AccessLogFilter#log

 1private void log(String accesslog, String logmessage) {
 2        init();                                                             // @1
 3        Set<String> logSet = logQueue.get(accesslog);                                            // @2 start
 4        if (logSet == null) {
 5            logQueue.putIfAbsent(accesslog, new ConcurrentHashSet<String>());
 6            logSet = logQueue.get(accesslog);
 7        }
 8        if (logSet.size() < LOG_MAX_BUFFER) {                                                   // @2 end
 9            logSet.add(logmessage);
10        }
11    }

代码@1:授权通过init方法启动定时任务,已间隔5s,延迟5s后执行第一次调度,具体的任务实现为LogTask。

 1private void init() {
 2        if (logFuture == null) {
 3            synchronized (logScheduled) {
 4                if (logFuture == null) {
 5                    logFuture = logScheduled.scheduleWithFixedDelay(new LogTask(), LOG_OUTPUT_INTERVAL, LOG_OUTPUT_INTERVAL, 
 6                           TimeUnit.MILLISECONDS);
 7                }
 8            }
 9        }
10    }

代码@2:以文件路径名accesslog为键,从logQueue中获取,如果当前处理的长度大于LOG_MAX_BUFFER固定为5000条,则丢弃。由于存储日志的容器为ConcurrentHashSet,则日志记录是乱序的。

具体异步记录日志的任务实现为AccessLogFilter$LogTask。

 1private class LogTask implements Runnable {
 2        @Override
 3        public void run() {
 4            try {
 5                if (logQueue != null && logQueue.size() > 0) {
 6                    for (Map.Entry<String, Set<String>> entry : logQueue.entrySet()) {
 7                        try {
 8                            String accesslog = entry.getKey();
 9                            Set<String> logSet = entry.getValue();
10                            File file = new File(accesslog);              
11                            File dir = file.getParentFile();  
12                            if (null != dir && !dir.exists()) {
13                                dir.mkdirs();
14                            }     // @1
15                            if (logger.isDebugEnabled()) {
16                                logger.debug("Append log to " + accesslog);
17                            }
18                            if (file.exists()) {    // @2
19                                String now = new SimpleDateFormat(FILE_DATE_FORMAT).format(new Date());
20                                String last = new SimpleDateFormat(FILE_DATE_FORMAT).format(new Date(file.lastModified()));
21                                if (!now.equals(last)) {
22                                    File archive = new File(file.getAbsolutePath() + "." + last);
23                                    file.renameTo(archive);
24                                }
25                            }
26                            FileWriter writer = new FileWriter(file, true);
27                            try {
28                                for (Iterator<String> iterator = logSet.iterator();
29                                     iterator.hasNext();
30                                     iterator.remove()) {
31                                    writer.write(iterator.next());
32                                    writer.write("\r\n");
33                                }
34                                writer.flush();
35                            } finally {
36                                writer.close();
37                            }
38                        } catch (Exception e) {
39                            logger.error(e.getMessage(), e);
40                        }
41                    }
42                }
43            } catch (Exception e) {
44                logger.error(e.getMessage(), e);
45            }
46        }
47    }

代码@1:从这里可以看出accesslog配置的是具体的日志文件全路径,例如d:/logs/accesslog.log。

代码@2:如果文件存在,则需要判断该文件的最后修改时间与当前日期是否相同,如果不同,则首先将文件重新命名为前一天的日期,然后再创建一个新的accesslog文件,也就是accesslog文件的布局是一天一个文件。

accesslog调用日志记录就分析到这里,我们思考一下开启该参数对服务提供者的性能影响。

  1. accesslog="true",其实现为通过log4j等日志组件,使用info级别将调用日志输出,该方法对服务调用者的影响还是比较大,不建议这样使用。
  2. accesslog="日志文件路径",该方式,dubbo使用的是异步记录日志的方式,开启额外的信息,主要是需要组织日志内容,耗费一定的CPU资源,但对服务的响应整体性能损耗还是不会起到恶劣的影响。默认情况下,还是不建议开启,但是如果线上服务器有BUG,需要通过调用日志来拍错的话,也可以在不重启服务提供者的情况下开启,开启方法利用Dubbo的配置覆盖机制,该部分的内容详情请参考作者的另一篇推文:源码分析Dubbo override协议

本文分享自微信公众号 - 中间件兴趣圈(dingwpmz_zjj)

原文出处及转载信息见文内详细说明,如有侵权,请联系 yunjia_community@tencent.com 删除。

原始发表时间:2019-03-31

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

我来说两句

0 条评论
登录 后参与评论

相关文章

  • 源码分析 Sentinel DegradeSlot 熔断实现原理

    Sentinel 中的熔断实现类为 DegradeSlot。DegradeSlot 的类定义如下图所示:

    丁威
  • 【图文并茂】源码解析MyBatis Sharding-Jdbc SQL语句执行流程详解

    本文将详细介绍Mybatis SQL语句执行的全流程,本文与上篇具有一定的关联性,建议先阅读该系列中的前面3篇文章,重点掌握Mybatis Mapper类的初始...

    丁威
  • 源码分析 RocketMQ DLedger(多副本) 之日志复制-上篇

    本文紧接着 源码分析 RocketMQ DLedger(多副本) 之日志追加流程 ,继续 Leader 处理客户端 append 的请求流程中最至关重要的一环...

    丁威
  • 漏洞复现 | WordPress 4.2.0-4.5.1 flashmediaelement.swf 反射型 XSS

    首先来看存在漏洞的输出, 99%的Flash XSS都是由于ExternalInterface.call函数的参数注入导致的, 当然本次也不例外. 拿到源码之后...

    TeamsSix
  • TOP语句放到表值函数外,效率异常低下

    在XXX系统中,有一个获取客户数据的SQLSERVER 表值函数,如果使用管理员登录,这个函数会返回150W行记录,大概需要30秒左右,但如果将TOP语句放到表...

    用户1177503
  • apollo在liunx环境实战(三)

    老梁
  • 【Kafka】消息订阅框架Kafka

    版权声明:本文为博主原创文章,转载请注明出处。 https://blog.csdn.net/gon...

    魏晓蕾
  • Android截屏的几种实现

    此种方式比较简单只需传入当前要截取屏幕的Activity对象即可,不需要添加任何权限,后续可将截图的bitmap保存到本地即可;

    IT大飞说
  • 网络工程师进阶 | 我不常用的命令以及不经常注意的地方—MPLS部分

    transport address为LSR的传输地址 默认和router-id相等

    网络技术联盟站
  • 关于微信指数,你可能最想了解的9个问题

    昨晚,在大家观战国足战胜韩足正酣时,我们上线了“微信指数”的功能(戳)。 关于“微信指数”,大家在“刷屏”的同时,也产生了很多好奇,我们一一为大家解答: Q1...

    腾讯大讲堂

扫码关注云+社区

领取腾讯云代金券