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

本人花费半年的时间总结的《Java面试指南》已拿腾讯等大厂offer,已开源在github ,欢迎star!

转载声明:转载请注明出处,本技术博客是本人原创文章

本文GitHub https://github.com/OUYANGSIHAI/JavaInterview 已收录,这是我花了6个月总结的一线大厂Java面试总结,本人已拿大厂offer,欢迎star

原文链接:blog.ouyangsihai.cn >> 源码分析Dubbo服务调用日志(accesslog参数)实现原理

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

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

AccessLogFilter概述

  • 过滤器作用 记录调用日志。

  • 使用场景 记录服务提供者端调用日志。

  • 阻断条件 非阻断过滤器。

    接下来源码分析accesslog参数的实现原理。

    源码分析Dubbo服务调用日志(accesslog参数)实现原理
  • 使用场景
    记录服务提供者端调用日志。

    接下来源码分析accesslog参数的实现原理。

    核心字段说明

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

    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        SetString logSet = logQueue.get(accesslog);                                            // @2 start
     4        if (logSet == null) {
     5            logQueue.putIfAbsent(accesslog, new ConcurrentHashSetString());
     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.EntryString, SetString entry : logQueue.entrySet()) {
     7                        try {
     8                            String accesslog = entry.getKey();
     9                            SetString 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 (IteratorString iterator = logSet.iterator();
    29                                     iterator.hasNext();
    30                                     iterator.remove()) {
    31                                    writer.write(iterator.next());
    32                                    writer.write("rn");
    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调用日志记录就分析到这里,我们思考一下开启该参数对服务提供者的性能影响。

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

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

    《RocketMQ技术内幕》已出版上市,目前可在主流购物平台(京东、天猫等)购买,本书从源码角度深度分析了RocketMQ NameServer、消息发送、消息存储、消息消费、消息过滤、主从同步HA、事务消息;在实战篇重点介绍了RocketMQ运维管理界面与当前支持的39个运维命令;并在附录部分罗列了RocketMQ几乎所有的配置参数。本书得到了RocketMQ创始人、阿里巴巴Messaging开源技术负责人、Linux OpenMessaging 主席的高度认可并作序推荐。目前是国内第一本成体系剖析RocketMQ的书籍。
    新书7折优惠!7折优惠!7折优惠!

    更多文章请关注微信公众号:

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

    推荐关注微信公众号:RocketMQ官方微信公众号

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

    原文始发于微信公众号(中间件兴趣圈):

    本人花费半年的时间总结的《Java面试指南》已拿腾讯等大厂offer,已开源在github ,欢迎star!

    转载声明:转载请注明出处,本技术博客是本人原创文章

    本文GitHub https://github.com/OUYANGSIHAI/JavaInterview 已收录,这是我花了6个月总结的一线大厂Java面试总结,本人已拿大厂offer,欢迎star

    原文链接:blog.ouyangsihai.cn >> 源码分析Dubbo服务调用日志(accesslog参数)实现原理


     上一篇
    源码分析Dubbo服务提供者、服务消费者并发度控制机制 源码分析Dubbo服务提供者、服务消费者并发度控制机制
    微信公众号:**[中间件兴趣圈]** 作者简介:《RocketMQ技术内幕》 本文将详细分析dubbo:service executes=””/与dubbo:reference actives = “”/的实现机制,深入探讨Dubb
    2021-04-05
    下一篇 
    源码分析Dubbo异步调用与事件回调机制 源码分析Dubbo异步调用与事件回调机制
    微信公众号:**[中间件兴趣圈]** 作者简介:《RocketMQ技术内幕》作者 本文将详细分析Dubbo服务异步调用与事件回调机制。 异步调用与事件回调机制TTY异步回调事件回调异步调用与事件回调机制在Dubbo中,引入特定的过滤
    2021-04-05