Jlog源码解析

357 阅读24分钟

引言

在日常工作中,相信读者在项目中或多或少会进行日志的打印,然而当我们使用常用的日志组件,如log4j、slf4j时,这些组件的默认策略都是直接将日志保存在服务器的日志文件中,它存在几个问题

  1. 从开发者排查问题/调试的角度:

    1. 每次希望查看日志时,需要登到具体某个机器上的某个特殊目录下,然后查看日志。
    2. 多实例部署时,日志分散存储。如果我们希望定位某个问题,我们要登上多个物理机查看日志。
  2. 从日志存储的角度

    1. 如果我们在另一台机器上部署了应用,那么之前打印的日志就不复存在。
    2. 通常日志框架都会设置7天过期,超过7天的日志会被删除。如果我们延长该时间,又会造成占用服务器资源。

互联网开发者们针对这些问题,提出了很多方案,这些方案通常需要几个组件

  1. 日志生成组件:应用程序、服务、操作系统或设备在运行过程中产生的日志信息。

    1. Java项目中通常使用log4j、logback、slf4j等组件将日志生成在文件中。
    2. 有些框架选择自己实现这部分逻辑,将日志生成在内存中。
  2. 日志采集组件:负责从日志生成源实时收集日志数据。

    1. 推模式(Push-based):主动从日志数据源(如应用程序、服务或设备)获取日志信息,并将它们发送到一个集中的日志存储或处理系统。如:Filebeat、Logtail

      1. Filebeat:一个轻量级的日志数据收集工具,属于Elastic公司的Elastic Stack生态系统的一部分。Filebeat通过轮询监视数据源,将新数据采集并发送到目标位置,同时确保数据的安全传输和可靠性。
      2. Logtail:阿里云日志服务提供的日志采集Agent,用于采集服务器上的日志,支持多种数据源和灵活的采集策略,具有实时采集日志、自动处理日志轮转等功能。
    2. 拉模式(Pull-based):日志存储或处理系统主动向日志采集组件请求日志数据,如我们通过日志查询服务查看某个日志时,日志查询服务器实时去某个应用服务器上拉日志,该方案不常见,但在某些特定场景下,如日志数据源不允许外部组件主动连接时,可能会采用这种方式。

    3. 两者两结合:Logstash 的工作方式可以视为一种拉(Pull)和推(Push)的结合:推模式(Push-based):当 Logstash 配置为从日志文件、数据库或消息队列等数据源主动拉取数据时,它表现出推模式的特点。数据源生成数据后,Logstash 会定期检查并拉取新数据。拉模式(Pull-based):当 Logstash 配置为从网络协议(如 Syslog)、APIs 或其他实时数据流中接收数据时,它表现出拉模式的特点。在这种情况下,数据源将数据推送到 Logstash。

  3. 数据存储和索引:用于长期存储日志数据的系统

    1. 如 Elasticsearch、Amazon S3、HDFS 或 Loki 等。这些系统应该具备高可靠性、可扩展性和高效的数据检索能力。
  4. 日志可视化与仪表板:

    1. Grafana、Kibana 或 Splunk 提供了丰富的可视化功能,帮助用户通过图表、仪表板等形式理解日志数据。

我们可以看到,以上的解决方案通常都包含多个组件,且可以自由组合。然而,还有一些厂商/开源社区 提出了一整套的解决方案

  1. PowerJob日志系统:PowerJob的日志系统以其小巧但功能强大的特点,实现了高效、可靠的日志收集和处理。它采用分布式架构,每个节点都有日志收集器,并将日志发送到中心服务器统一处理
  2. ​​Jlog:来自京东App秒级百G级日志搜集、传输、存储解决方案。较ELK系列方案(filebeat、mq传输、es存储等常见方案),该框架拥有10倍以上的性能提升,和70%以上的磁盘节省。这意味着,在日志这个功能块上,使用相同的硬件配置,原本只能传输、存储一秒100M的日志,采用该方案,一秒可以处理1GB的日志,且将全链路因日志占用的磁盘空间下降70%。(引用自JLog Readme)

下面,我们正式进入JLog的世界,来剖析JLog框架。

看本文前,可以先浏览 京东 App 秒级百 G 日志传输存储架构设计与实战 一文,该文章出自框架的作者,详细叙述了框架的架构设计以及为何这样设计,写的非常好。想单纯了解该框架的架构设计,直接看该文章即可。如果想继续深入了解该框架的源码细节,可以继续往下浏览。

总体逻辑​​

jlog-第 2 页.drawio 1.svg

client端逻辑

1、日志生产端

日志生产端主要逻辑是,client采集日志后,把数据放到tracerBeanQueue​和logBeanQueue​两个队列。

为什么是两个队列呢?因为Jlog框架将日志大致分为两类,

  • 一类是对常用的框架,如Spring MVC的请求和响应进行采集,然后生成的日志,采集后放到tracerBeanQueue​中。
  • 一类是调用日志框架打印的日志,如我们常用的logger.info​, logger.error​ 等操作生成的日志,采集后放到logBeanQueue​中。

首先看对Spring MVC的请求和响应的采集

在client包下,Jlog提供了一个filter:HttpFilter​用于对request和response进行采集,然后压缩后,结合uri,traceId,appname,costTime等信息写入tracerBeanQueue​。

如果我们需要使用该Filter,借助如下代码进行配置

@Component
public class Starter {
    @Bean
    public FilterRegistrationBean urlFilter() {
        FilterRegistrationBean registration = new FilterRegistrationBean();
        HttpFilter userFilter = new HttpFilter();
        registration.setFilter(userFilter);
        registration.addUrlPatterns("/*");
        registration.setName("UserTraceFilter");
        registration.setOrder(1);
        return registration;
    }
}

通过FilterRegistrationBean​让HttpFilter​拦截一切请求,这样当请求被打到服务器时,就会执行HttpFilter​的doFilter​方法

@Override
public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
    HttpServletResponse resp = (HttpServletResponse) servletResponse;
    RequestWrapper requestWrapper = new RequestWrapper((HttpServletRequest) servletRequest);
    long currentTImeMills = System.currentTimeMillis();
    String uri = requestWrapper.getRequestURI().replace("/", "");
    //设置随机数
    Random random = new Random(currentTImeMills);
    //1-100之间
    int number = random.nextInt(100) + 1;
    //此处要有个开关,控制百分比
    if (iTracerPercent.percent() < number) {
        filterChain.doFilter(requestWrapper, servletResponse);
        return;
    }
    //如果是要忽略的接口,就继续执行,不搜集信息
    if (iTracerPercent.ignoreUriSet() != null && iTracerPercent.ignoreUriSet().contains(uri)) {
        filterChain.doFilter(requestWrapper, servletResponse);
        return;
    }
    //链路唯一Id
    long tracerId = IdWorker.nextId();
    TracerHolder.setTracerId(tracerId);
    TracerBean tracerBean = new TracerBean();
    tracerBean.setTracerId(tracerId);
    tracerBean.setCreateTimeLong(System.currentTimeMillis());
    tracerBean.setUri(uri);
    tracerBean.setApp(Context.APP_NAME);

    //处理request的各个入参
    parseRequestMap(requestWrapper, tracerBean);
    try {
        //处理response
        tracerBean.setResponseContent(dealResponseMap(requestWrapper, servletResponse,
                resp, filterChain));
    } catch (Exception e) {
        //异常信息
        tracerBean.setErrmsg(LogExceptionStackTrace.erroStackTrace(e).toString());
        filterChain.doFilter(requestWrapper, servletResponse);
    }finally {
        //设置耗时
        tracerBean.setCostTime((System.currentTimeMillis() - tracerBean.getCreateTimeLong()));
        //udp发送
        UdpSender.offerBean(tracerBean);
    }
}

主要逻辑为

  1. 如果按照百分比采集或者有些接口需要忽略,那就不执行日志搜集逻辑。
  2. 调用IdWorker.nextId()​利用雪花算法生成一个唯一id,设置到TransmittableThreadLocal​中
  3. 将请求的入参封装到TracerBean​的uid 和 requestContent​中
  4. 将响应的结果写到TracerBean​的responseContent​中
  5. 如果发生异常,将异常信息写入TracerBean​的errmsg​中
  6. 将耗时写入TracerBean​的costTime​中
  7. 调用UdpSender.offerBean(tracerBean)​将TracerBean​写到tracerBeanQueue​中。
IdWorker.nextId()
//雪花算法生成id
public static long nextId() {
    long time = System.currentTimeMillis();
    // 如果时钟回溯,就报错
    if (lastTime > time) {
        throw new RuntimeException("Clock is moving backwards, last time is %d milliseconds, current time is %d milliseconds" + lastTime);
    }
    // 如果当前时间和上次生成ID的时间相同,则sequence自增1,如果自增后发现是0,则等下一个时间戳
    // 如果当前时间和上次生成ID的时间不相同,则sequence从0开始
    if (lastTime == time) {
        if (0L == (sequence = ++sequence & SEQUENCE_MASK)) {
            time = waitUntilNextTime(time);
        }
    } else {
        sequence = 0;
    }
    // 记录本次生成ID的时间
    lastTime = time;
    // 雪花算法生生成id,时间戳为 当前时间 - 2017.3.1的时间戳, workerId是根据ip地址确定的
    return ((time - EPOCH) << TIMESTAMP_LEFT_SHIFT_BITS) | (workerId << WORKER_ID_LEFT_SHIFT_BITS) | sequence;
}
请求入参的封装
// Filter中将servletRequest包装成RequestWrapper
RequestWrapper requestWrapper = new RequestWrapper((HttpServletRequest) servletRequest);
// 处理request的各个入参
parseRequestMap(requestWrapper, tracerBean);
/**
  * 处理入参相关信息
  */
private void parseRequestMap(RequestWrapper requestWrapper, TracerBean tracerBean) {
    // 获取request的各个入参,封装到变量requestMap中
    Map<String, String[]> params = requestWrapper.getParameterMap();
    Map<String, Object> requestMap = new HashMap<>(params.size());
    for (String key : params.keySet()) {
        requestMap.put(key, params.get(key)[0]);
    }
    // 将请求参数中的uid设置到tracerBean中
    tracerBean.setUid((String) requestMap.get("uid"));

    //对于@RequestBody类型的,可以通过该方法读取字符串。是个json串
    String body = requestWrapper.getBody();
    if (StringUtil.isNotBlank(body)) {
        //将json转成map
        Map<String, Object> jsonMap = FastJsonUtils.toMap(body);
        // 设置到requestMap中
        requestMap.putAll(jsonMap);
    }

    // 根据配置判断是否提取以及是否压缩,获得 Outcome,其中包括提取的tag以及将这些tag作为json字符串进行压缩
    Outcome out = ClientHandler.processReq(requestMap);
    // 设置到 tracerBean的 requestContent中
    tracerBean.setRequestContent((byte[]) out.getContent());
}

处理入参的逻辑主要包括两大功能

  1. 提取请求中的标签,具体该提取哪些标签,可配置

    • 代码逻辑中先将所有的请求参数和body中的参数封装成map,然后根据配置的标签进行匹配,哪些需要入日志,因为请求参数量大,全部都保存也不现实,所以可以通过配置选择性地保存某些请求参数到配置中。
  2. 请求可能会很大,比如上传图片,上传视频等,所以会根据配置决定是否将请求的内容进行压缩

其中重点看一下

Outcome out = ClientHandler.processReq(requestMap);
public static Outcome processReq(Map<String, Object> reqMap){
    // 根据配置决定是否提取 tag标签
    Map<String, Object> tag = ExtractHandler.extractReqTag(reqMap);
    // 根据配置决定是否压缩tagMap
    return CompressHandler.compressReq(tag);
}

根据配置决定是否提取 tag标签

/**
  * 提取请求参数里的标签
  * @param reqMap 额外附加的,如ip等
  * @return tags
  */
public static Map<String, Object> extractReqTag(Map<String, Object> reqMap) {
  
    if(instance == null || !isMatched(instance.extract, E_REQ) || CollectionUtil.isEmpty(reqMap)){
        return null;
    }
    Map<String, Object> tagMap = new HashMap<>(instance.reqTags.size());
    for (String tag : instance.reqTags) {
        Object val = reqMap.get(tag);
        if(val != null){
            tagMap.put(tag, val);
        }
    }return tagMap;
}

怎么根据配置呢?

isMatched(instance.extract, E_REQ)

instance.extract 是从配置文件中读的,E_REQ​是个常量 1,isMatched​就是判断按位与,是否是该常量。

因此,我们如果想要配置不提取req,直接将instance.extract的最小位配置为0即可。

public static boolean isMatched(long indicator, long position) {
    return (indicator & position) == position;
}
// 根据配置决定是否压缩tagMap
CompressHandler.compressReq(tag)
/**
  * req一般无需压缩 除非图片base64等触发压缩
  * @param map tagMap
  * @return Outcome
  */
public static Outcome compressReq(Map<String, Object> map){
    if(instance == null || CollectionUtil.isEmpty(map) || !isMatched(instance.compress, C_REQ)){
        return new Outcome(map);
    }
    return new Outcome(map, ZstdUtils.compress(JSON.toJSONBytes(map)));
}
响应的封装
//处理response
tracerBean.setResponseContent(dealResponseMap(requestWrapper, servletResponse, resp, filterChain));
/**
 * 处理出参相关信息
 */
private byte[] dealResponseMap(ServletRequest servletRequest, ServletResponse servletResponse, HttpServletResponse resp,
                                FilterChain filterChain) throws IOException, ServletException {
    // 包装响应对象 resp 并缓存响应数据
    ResponseWrapper mResp = new ResponseWrapper(resp);
    filterChain.doFilter(servletRequest, mResp);
    // 把响应内容取出来,转成map
    byte[] contentBytes = mResp.getContent();
    String content = new String(contentBytes);

    Map<String, Object> map = FastJsonUtils.toMap(content);

    // 根据配置判断是否提取tag,以及是否压缩
    Outcome outcome = ClientHandler.processResp(contentBytes, map);

    //此处可以对content做处理,然后再把content写回到输出流中
    servletResponse.setContentLength(-1);
    PrintWriter out = servletResponse.getWriter();
    out.write(content);
    out.flush();
    out.close();

    return (byte[]) outcome.getContent();
}

响应和请求一样

  1. 根据配置判断是否需要提取tag
  2. 根据配置判断是否需要压缩

将请求以及响应,以及发生异常的异常信息,耗时都保存到TracerBean​中后,就调用UdpSender.offerBean(tracerBean)​将TracerBean​写到tracerBeanQueue​中。

/**
 * 写入队列
 */
public static void offerBean(TracerBean tracerModel) {
    //容量是否已满
    boolean success = tracerBeanQueue.offer(tracerModel);
    if (!success) {
        long failCount = FAIL_OFFER_COUNT.incrementAndGet();
        if (failCount % 10 == 0) {
            logger.info("用户跟踪队列已满,当前丢弃的数量为: " + failCount);
        }
    } else {
        long successCount = SUCCESS_OFFER_COUNT.incrementAndGet();
        if (successCount % 1000 == 0) {
            logger.info("用户跟踪已产生数量:" + successCount + ",当前队列积压数量:" + tracerBeanQueue.size());
        }
    }
}

调用offer​方法将TracerBean​加到tracerBeanQueue​中,如果队列中还有空间,返回true,否则返回false。

如果返回false,则直接丢弃,并记录丢弃的数量后,打印日志。

日志框架打印的日志搜集

image.png

在logback-spring.xml​中,配置了一个TracerLogbackAppender​,这样当我们调用logger.info​或者 logger.error​时,会调用TracerLogbackAppender#append​的方法

每当调用TracerLogbackAppender#append​方法时,会调用getLogMessage​方法将iLoggingEvent​转化为RunLogMessage​,写入logBeanQueue​中。

@Override
protected void append(ILoggingEvent iLoggingEvent) {
    try {
        long tracerId = TracerHolder.getTracerId();
        if (0L == tracerId) {
            return;
        }
        RunLogMessage logMessage = getLogMessage(iLoggingEvent);
        UdpSender.offerLogger(logMessage);
    } catch (Exception e) {
        e.printStackTrace();
    }
}

getLogMessage转化方法如下:

/**
 * 转化为对象
 */
private RunLogMessage getLogMessage(ILoggingEvent loggingEvent) {
    RunLogMessage logMessage = new RunLogMessage();
    //设置链路唯一id
    logMessage.setTracerId(TracerHolder.getTracerId());
    logMessage.setClassName(loggingEvent.getLoggerName());
    logMessage.setThreadName(loggingEvent.getThreadName());

    StackTraceElement stackTraceElement = loggingEvent.getCallerData()[loggerStage];

    String method = stackTraceElement.getMethodName();
    String line = String.valueOf(stackTraceElement.getLineNumber());
    logMessage.setMethodName(method + "(" + stackTraceElement.getFileName() + ":" + line + ")");
    logMessage.setLogLevel(loggingEvent.getLevel().toString());

    logMessage.setCreateTime(loggingEvent.getTimeStamp());

    String formattedMessage = getMessage(loggingEvent);
    Outcome out = ClientHandler.processLog(formattedMessage);
    // 放入标签
    logMessage.setTagMap(out.getTagMap());
    // 放入内容 可能已经被压缩了
    logMessage.setContent(formattedMessage);
    return logMessage;
}

其中,我们可以看到该方法将loggingEvent​的属性都赋值给RunLogMessage​。但其中有一串特殊的代码

String formattedMessage = getMessage(loggingEvent);
Outcome out = ClientHandler.processLog(formattedMessage);
// 放入标签
logMessage.setTagMap(out.getTagMap());
// 放入内容 可能已经被压缩了
logMessage.setContent(formattedMessage);

该代码将loggingEvent​中的日志正文信息转化为了字符串,并提取log标签后,赋值给logMessage​。

/**
 * 日志正文信息
 */
private String getMessage(ILoggingEvent logEvent) {
    if (logEvent.getLevel() == Level.ERROR) {
        if (logEvent.getThrowableProxy() != null) {
            ThrowableProxy throwableProxy = (ThrowableProxy) logEvent.getThrowableProxy();
            String[] args = new String[]{logEvent.getFormattedMessage() + "\n" + LogExceptionStackTrace.erroStackTrace(throwableProxy.getThrowable()).toString()};
            return packageMessage("{}", args);
        } else {
            Object[] args = logEvent.getArgumentArray();
            if (args != null) {
                for (int i = 0; i < args.length; i++) {
                    if (args[i] instanceof Throwable) {
                        args[i] = LogExceptionStackTrace.erroStackTrace(args[i]);
                    }
                }
                return packageMessage(logEvent.getMessage(), args);
            }
        }
    }
    return logEvent.getFormattedMessage();
}

再看TracerLogbackAppender#append​方法中,当生成了RunLogMessage​后,调用的UdpSender.offerLogger(logMessage);​方法

RunLogMessage logMessage = getLogMessage(iLoggingEvent);
UdpSender.offerLogger(logMessage);

然后将RunLogMessage​写到logBeanQueue​中

/**
 * 写入log队列
 */
public static void offerLogger(RunLogMessage runLogMessage) {
    //容量是否已满
    boolean success = logBeanQueue.offer(runLogMessage);
    if (!success) {
        long failCount = FAIL_OFFER_COUNT.incrementAndGet();
        if (failCount % 10 == 0) {
            logger.info("用户Logger队列已满,当前丢弃的数量为: " + failCount);
        }
    } else {
        long successCount = SUCCESS_LOGGER_OFFER_COUNT.incrementAndGet();
        if (successCount % 10000 == 0) {
            logger.info("用户Logger已产生数量:" + successCount + ",当前队列积压数量:" + logBeanQueue.size());
        }
    }
}

小结

至此,我们分析完了client端的日志采集流程,主要通过HttpFilter​和TracerLogbackAppender​将日志分别封装成TracerBean(其中请求和响应根据配置决定是否压缩)和RunLogMessage。

2. 日志消费端

client采集日志后,把数据放到tracerBeanQueue​和logBeanQueue​两个队列后,后续的工作呢?如何将这些内存队列中的数据搜集到服务端呢?

首先我们从client​模块下的TracerClientStarter#startPipeline​方法开始看起

/**
 * 启动监听
 */
public void startPipeline() {
    // 初始化配置
    initJLogConfig();

    Context.MDC = mdc;

    ModeHolder.setSendMode(this.sendMode);

    Monitor starter = new Monitor();
    starter.start();

    UdpClient udpClient = new UdpClient();
    udpClient.start();

    //开启发送
    UdpSender.uploadToWorker();

    //开启大对象http发送
    HttpSender.uploadToWorker();
}

最关键的就是三部分代码

1. 开始获取workerIp地址并保存

Monitor starter = new Monitor();
starter.start();

public void start() {
    fetchWorkerInfo();
}



/**
 * 每隔30秒拉取worker信息
 */
private void fetchWorkerInfo() {
    ScheduledExecutorService scheduledExecutorService = Executors.newSingleThreadScheduledExecutor();
    //开启拉取etcd的worker信息,如果拉取失败,则定时继续拉取
    scheduledExecutorService.scheduleAtFixedRate(() -> {
        LOGGER.info("trying to connect to config center and fetch worker info");
        try {
            fetch();
        } catch (Exception e) {
            e.printStackTrace();
        }

    }, 0, 30, TimeUnit.SECONDS);
}


/**
 * 从配置中心获取worker的ip集合
 */
private void fetch() throws Exception {
    Configurator configurator = ConfiguratorFactory.getInstance();
    //获取所有worker的ip
    List<String> addresses;
    try {
        //如果设置了机房属性,则拉取同机房的worker。如果同机房没worker,则拉取所有
        addresses = configurator.getList("workers");
        //全是空,给个警告
        if (addresses == null || addresses.size() == 0) {
            LOGGER.warn("very important warn !!! workers ip info is null!!!");
            return;
        }
        //将对应的worker保存下来
        WorkerInfoHolder.mergeAndConnectNew(addresses);
    } catch (Exception ex) {
        LOGGER.error("config server connected fail. Check the config address!!!");
    }

}

从上面的代码中可以看到,每隔30s定时执行fetch​方法,即从配置中心拉取worker信息,然后保存起来。

jlog模块提供了多种配置中心的实现

image.png

当从配置中心获取了worker信息后,调用下面一行代码将worker保存

WorkerInfoHolder.mergeAndConnectNew(addresses);
/**
 * 保存worker的ip地址和Channel的映射关系,这是有序的。每次client发送消息时,都会根据该map的size进行hash
 * 如key-1就发送到workerHolder的第1个Channel去,key-2就发到第2个Channel去
 */
private static final List<String> WORKER_HOLDER = new CopyOnWriteArrayList<>();


/**
 * 监听到worker信息变化后
 * 将新的worker信息和当前的进行合并,并且连接新的address
 * address例子:10.12.139.152:11111
 */
public static void mergeAndConnectNew(List<String> allAddresses) {
    if (allAddresses.size() == 0) {
        WORKER_HOLDER.clear();
        return;
    }
    //将新的进行排序
    Collections.sort(allAddresses);
    //对比是否两个list是否一样,如果一样就什么也不干
    if (WORKER_HOLDER.equals(allAddresses)) {
        return;
    }
    //变更WORKER_HOLDER
    WORKER_HOLDER.clear();
    WORKER_HOLDER.addAll(allAddresses);
}

逻辑简单粗暴,就是将配置中心的worker信息保存到本地。

2. 启动UDP相关逻辑

UdpClient udpClient = new UdpClient();
udpClient.start();

//开启发送
UdpSender.uploadToWorker();
先看udpClient.start();​
/**
 * startUdp
 */
private void startUdp() {
    //1.NioEventLoopGroup是执行者
    NioEventLoopGroup group = new NioEventLoopGroup();
    //2.启动器
    Bootstrap bootstrap = new Bootstrap();
    //3.配置启动器
    bootstrap.group(group)                         //3.1指定group
            .channel(NioDatagramChannel.class)     //3.2指定channel
            .handler(new ChannelInitializer<NioDatagramChannel>() {
                @Override
                protected void initChannel(NioDatagramChannel nioDatagramChannel) {
                    //3.4在pipeline中加入编码器,和解码器(用来处理返回的消息)
                    nioDatagramChannel.pipeline().addLast(new MyUdpEncoder());
                }
            });
    //4.bind并返回一个channel
    try {
        Channel channel = bootstrap.bind(8887).sync().channel();
        Context.CHANNEL = channel;

        //6.等待channel的close
        channel.closeFuture().sync();
        //7.关闭group
        group.shutdownGracefully();
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
}

这串代码就是简单的netty client的逻辑,只是在 netty的pipeline​中增加了一个encoder:MyUdpEncoder​,而这个MyUdpEncoder​就是重头戏

/**
 * 编码器,将要发送的消息(这里是一个String)封装到一个DatagramPacket中
 */
private static class MyUdpEncoder extends MessageToMessageEncoder<TracerData> {
    @Override
    protected void encode(ChannelHandlerContext channelHandlerContext, TracerData tracerData, List<Object> list) {
        // 序列化
        byte[] bytes = ProtostuffUtils.serialize(tracerData);
        // 压缩
        byte[] compressBytes = ZstdUtils.compress(bytes);

        //判断压缩完是否过大,过大走http接口请求worker
        if (compressBytes.length >= COMPRESS_BYTES_LEN) {
            //放入发okhttp的队列
            HttpSender.offerBean(compressBytes,tracerData.getAddress());
            return;
        }

        ByteBuf buf = channelHandlerContext.alloc().buffer(compressBytes.length);
        buf.writeBytes(compressBytes);
        InetSocketAddress remoteAddress=null;
        // 单播
        if(ModeHolder.getSendMode().getUnicast()){
            // 轮训挑选一个worker
            String workerIpPort =  WorkerInfoHolder.chooseWorker();
            if (workerIpPort == null) {
                return;
            }
            String[] ipPort = workerIpPort.split(Constant.SPLITER);
            //发往worker
            remoteAddress= new InetSocketAddress(ipPort[0], Integer.parseInt(ipPort[1]));
        }else{
            remoteAddress=tracerData.getAddress();
        }
        DatagramPacket packet = new DatagramPacket(buf, remoteAddress);
        list.add(packet);
    }
}

这个编码器的作用就是对TracerData​进行序列化,然后压缩成byte数组后,进行发送。然而,根据数据量的大小,大的数据使用Http进行发送,小的数据使用netty的udp发送。

  • 小数据量直接使用netty的udp就发送了

  • 大数据量不是直接通过Http进行发送,而是先放到一个队列tracerDataQueue​中,如果容量满了,就丢弃。

    /**
     * 写入队列
     */
    public static void offerBean(byte[] compressBytes, InetSocketAddress address) {
        if(address!=null){
            HttpSender.address=address;
        }
        OneTracer oneTracer = new OneTracer();
        oneTracer.setBytes(compressBytes);
        //容量是否已满
        boolean success = tracerDataQueue.offer(oneTracer);
        if (!success) {
            long failCount = FAIL_OFFER_COUNT.incrementAndGet();
            if (failCount % 10 == 0) {
                logger.info("用户跟踪大对象队列已满,当前丢弃的数量为: " + failCount);
            }
        } else {
            long successCount = SUCCESS_OFFER_COUNT.incrementAndGet();
            if (successCount % 1000 == 0) {
                logger.info("用户跟踪大对象已产生数量:" + successCount + ",当前大对象队列积压数量:" + tracerDataQueue.size());
            }
        }
    }
    

    那这个数据一定会在某一串代码中被取出来,然后发送出去。这就是涉及到client端的启动逻辑的第三部分了。我们在第三部分说。

再看UdpSender.uploadToWorker();​
/**
 * 定时向worker发送
 */
public static void uploadToWorker() {
    //filter拦截到的出入参
    AsyncPool.asyncDo(() -> {
        while (true) {
            try {
                List<TracerBean> tempTracers = new ArrayList<>();
                TracerBean tracerBean = tracerBeanQueue.take();
                tempTracers.add(tracerBean);

                TracerData tracerData = new TracerData();
                tracerData.setTracerBeanList(tempTracers);
                tracerData.setType(LogTypeEnum.SPAN);
                send(tracerData);
            } catch (Exception e) {
                e.printStackTrace();
            }
        }
    });
    //用户中途打的各日志
    AsyncPool.asyncDo(() -> {
        while (true) {
            try {
                //要么key达到500个,要么达到1秒,就汇总上报给worker一次
                List<RunLogMessage> tempLogs = new ArrayList<>();
                AsyncWorker.drain(logBeanQueue, tempLogs, 500, 1, TimeUnit.SECONDS);
                if (tempLogs.size() == 0) {
                    continue;
                }
                TracerData tracerData = new TracerData();
                tracerData.setTempLogs(tempLogs);
                tracerData.setType(LogTypeEnum.TRADE);
                send(tracerData);
            } catch (Exception e) {
                e.printStackTrace();
            }
        }
    });
}

/**
 * 往worker发traceBean
 */
private static void send(TracerData tracerData) throws InterruptedException {
	// 多播
    if(!ModeHolder.getSendMode().getUnicast()){
        List<String>ips= WorkerInfoHolder.selectWorkers();
        for(String ip:ips){
            String[] ipPort = ip.split(Constant.SPLITER);
            //发往worker的ip
            InetSocketAddress remoteAddress = new InetSocketAddress(ipPort[0], Integer.valueOf(ipPort[1]));
            tracerData.setAddress(remoteAddress);
            ChannelFuture future = Context.CHANNEL.writeAndFlush(tracerData);
            //同步操作,否则会出现bug
            future.sync();
        }
        return;
    }else {
		// 单播
        Context.CHANNEL.writeAndFlush(tracerData);
    }
}

这里干了两件事

  1. 从tracerBeanQueue​中死循环取出数据,封装成TracerData​,调用send​通过netty进行发送。
  2. 从logBeanQueue​中死循环取出数据,封装成TracerData​,调用send​通过netty进行发送。

唯一的区别就是type​,tracerBeanQueue​发送的消息的type是SPAN​,而logBeanQueue​中取出的消息发送的type是TRADE​。

小结
  1. 启动一个线程,死循环从tracerBeanQueue​和logBeanQueue​中取出数据,封装成TracerData​,然后调用netty进行发送

  2. netty发送时,会由netty的一个encoder​进行编码,它会进行序列化和压缩

    1. 小数据量直接使用netty的udp就发送了
    2. 大数据通过http进行发送,但是是先放到一个队列tracerDataQueue 中,如果容量满了,就丢弃。

那么问题来了,tracerDataQueue​中的大数据包怎么办呢?想着一定有一个线程,死循环从中取出数据,然后调用http进行发送。

3. 启动Http发送相关逻辑

//开启大对象http发送
HttpSender.uploadToWorker();
/**
 * 定时往worker发送
 */
public static void uploadToWorker() {
    //filter拦截到的出入参
    AsyncPool.asyncDo(() -> {
        while (true) {
            try {
                List<OneTracer> tempTracers = new ArrayList<>();
                //TODO 要不要多攒几个
                OneTracer tracerBean = tracerDataQueue.take();
                tempTracers.add(tracerBean);

                send(tempTracers);
            } catch (Exception e) {
                e.printStackTrace();
            }
        }
    });
}

/**
 * 发送OkHttp请求
 */
private static void send(List<OneTracer> tempTracers) {
    for (OneTracer one: tempTracers) {
        deal(one.getBytes());
    }
}


private static void deal(byte[] compressBytes) {
    /**
        * 所有HTTP请求的代理设置,超时,缓存设置等都需要在OkHttpClient中设置。 如果需要更改一个请求的配置,可以使用
        * OkHttpClient.newBuilder()获取一个builder对象,
        * 该builder对象与原来OkHttpClient共享相同的连接池,配置等。
        */
    client = client.newBuilder().build();

    RequestBody requestBody = RequestBody.create(MediaType.parse("application/octet-stream"), compressBytes);
    MultipartBody multipartBody = new MultipartBody.Builder()
            .setType(MultipartBody.FORM)
            .addFormDataPart("data", "data", requestBody)
            .build();

    String rawIpPort;
    String ipPort;
    if(ModeHolder.getSendMode().getUnicast()){
            //挑一个worker
            rawIpPort = WorkerInfoHolder.chooseWorker();
            ipPort = rawIpPort.substring(0, rawIpPort.lastIndexOf(":")) + ":8080";
    }else{
            //直接从TracerData中获取地址
            rawIpPort=HttpSender.address.getHostName();
            ipPort=rawIpPort+":8080";
    }

    String url = "http://" + ipPort + "/big/receive";

    Request request = new Request.Builder()
            .url(url)
            .post(multipartBody)
            .build();
    Call call = client.newCall(request);
    call.enqueue(new Callback() {
        @Override
        public void onFailure(Call call, IOException e) {
            logger.error("HttpSender  onFailure", e);
            call.cancel();
        }

        @Override
        public void onResponse(Call call, Response response) throws IOException {
            response.body().close();
        }
    });
}

从这一块逻辑就可以看到,有个线程死循环从tracerDataQueue​队列中取出数据,然后调用Http进行发送。

4. 启动流程小结

最后我们来总结一下,client的启动流程的内容

  1. 有个线程定时从配置中心拉取worker信息
  2. 开启一个线程死循环从tracerBeanQueue​和logBeanQueue​两个队列中取出数据,然后通过netty发送。而发送时,先序列化,再压缩。并且在netty的pipeLine中定义了一个MyUdpEncoder​,其中按照数据大小,小数据调用netty直接通过UDP发送,大数据则放到tracerDataQueue​队列中交由http发送。
  3. 开启一个线程死循环从tracerDataQueue​队列中取出数据通过http发送。

总结一下:client端的逻辑为:HttpFilter​和TracerLogbackAppender​(普通打日志,如 logger.info​ 产生的日志)生成的日志都会写入队列中(这里包含两个队列),这里注意,HttpFilter​生成日志的时候,会将request和response先进行压缩,再放到日志结构体中,然后client端的starter启动类会启动线程,死循环从两个队列中取数据,再对数据进行序列化,压缩,然后再发送。发送的时候,会经过一个编码器,编码器判断要发送的数据是否是大数据包,如果是大数据,那么就放到另一个队列中,会有一个线程死循环从队列中取数据,然后通过http发送。如果是小数据那么就直接通过netty发送给worker。

worker端逻辑

还记得client是怎么将日志发送给worker的嘛?通过两种方式,UDP和HTTP。那我们分别来看一下worker端针对这两个数据是怎么接受的?

首先看Http。

在com.jd.platform.jlog.worker.controller.BigTracerController中我们看到有个receiveBigTrace​方法

@RequestMapping("/receive")
public String receiveBigTrace(@RequestParam("data") MultipartFile file) {
    try {
        byte[] bytes = file.getBytes();
        producer.sendData(bytes);

        return "success";
    } catch (IOException e) {
        logger.error("BigTracerController.receiveBigTrace [error]", e);
    }
    return "false";
}

可以看到,内容很简单,就是接收数据后,交给producer进行处理。

而producer的逻辑也很简单,就是直接将数据写到ringBuffer中。

/**
 * 发送数据
 */
public void sendData(byte[] bytes) {
    if (bytes == null) {
        return;
    }

    long sequence = ringBuffer.next();
    totalOfferCount.increment();

    long totalReceive = totalOfferCount.longValue();
    if (totalReceive % 10000 == 0) {
        logger.info("生产消费队列,已接收:" + totalReceive);
    }
    try {
        OneTracer oneTracer = ringBuffer.get(sequence);
        oneTracer.setBytes(bytes);
    } finally {
        ringBuffer.publish(sequence);
    }
}

那针对UDP请求呢?

/**
 * 启动server监听器
 */
public void startServer() {
    //1.NioEventLoopGroup是执行者
    NioEventLoopGroup group = new NioEventLoopGroup(1);
    //2.启动器
    Bootstrap bootstrap = new Bootstrap();
    //3.配置启动器
    bootstrap.group(group)//3.1指定group
            .channel(NioDatagramChannel.class)//3.2指定channel
            .option(ChannelOption.RCVBUF_ALLOCATOR, new FixedRecvByteBufAllocator(65535))
            .handler(new ChannelInitializer<NioDatagramChannel>() {
                @Override
                protected void initChannel(NioDatagramChannel nioDatagramChannel) {
                    //3.4在pipeline中加入解码器,和编码器(用来发送UDP)
                    nioDatagramChannel.pipeline().addLast(new TracerBeanDecoder());
                }
            });
    try {
        //4.bind到指定端口,并返回一个channel,该端口就是监听UDP报文的端口
        Channel channel = bootstrap.bind(9999).sync().channel();
        //5.等待channel的close
        channel.closeFuture().sync();
        //6.关闭group
        group.shutdownGracefully();
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
}

上面这串代码就是在9999端口起了一个netty server,只是引入了一个Decoder:​TracerBeanDecoder​

/**
 * 解码器,解析客户端发来的对象
 */
private class TracerBeanDecoder extends MessageToMessageDecoder<DatagramPacket> {
    @Override
    protected void decode(ChannelHandlerContext channelHandlerContext, DatagramPacket datagramPacket, List<Object> list) {
        ByteBuf buf = datagramPacket.content();

        byte[] body = new byte[buf.readableBytes()];
        buf.readBytes(body);
        producer.sendData(body);
    }
}

可以看到,这里Decoder的逻辑和之前的controller逻辑相似,也是将数据交给producer​,从而交给ringBuffer​。

我们再来关注以下RingBuffer​在哪里消费的?

在DisruptorStarter​类中我们可以看到

@Configuration
public class DisruptorStarter {

    /**
     * 消费者线程数量
     */
    @Value("${thread.count}")
    private int threadCount;
    /**
     * TracerToDbStore
     */
    @Resource
    private TracerModelToDbStore tracerModelToDbStore;
    /**
     * tracerLogToDbStore
     */
    @Resource
    private TracerLogToDbStore tracerLogToDbStore;
    /**
     * 队列最大容量,1024*16,也就是RingBuffer大小,必须是2的N次方
     */
    @Value("${queue.maxSize}")
    private int maxSize;

    @Bean
    public Producer init() {
        ThreadFactory producerFactory = Executors.defaultThreadFactory();

        EventFactory<OneTracer> eventFactory = OneTracer::new;
        Disruptor<OneTracer> disruptor = new Disruptor<>(eventFactory, maxSize, producerFactory,
                ProducerType.SINGLE, new BlockingWaitStrategy());

        // 创建10个消费者来处理同一个生产者发的消息(这10个消费者不重复消费消息)
        TracerConsumer[] consumers = new TracerConsumer[threadCount];
        for (int i = 0; i < consumers.length; i++) {
            consumers[i] = new TracerConsumer(tracerModelToDbStore, tracerLogToDbStore);
        }
        disruptor.handleEventsWithWorkerPool(consumers);

        RingBuffer<OneTracer> ringBuffer = disruptor.start();

        return new Producer(ringBuffer);
    }
}

这里根据threadCount​构造了多个TracerConsumer​,然后使用TracerConsumer​来作为Disruptor​的消费者。我们来看一下TracerConsumer​的逻辑

直接看TracerConsumer​的onEvent方法

@Override
public void onEvent(OneTracer oneTracer) {
    try {
        long totalConsume = totalDealCount.longValue();
        boolean needInfo = totalConsume % 1000 == 0;

        //解压后的字节数组
        byte[] decompressBytes = ZstdUtils.decompressBytes(oneTracer.getBytes());
		// 反序列化
        TracerData tracerData = ProtostuffUtils.deserialize(decompressBytes, TracerData.class);

        //消费处理
        buildTracerModel(tracerData);

        //处理完毕,将数量加1
        totalDealCount.increment();

    } catch (Exception e) {
        e.printStackTrace();
    }
}

/**
 * 构建要入库的对象
 */
private void buildTracerModel(TracerData tracerData) {
    //普通日志
    if (LogTypeEnum.TRADE.equals(tracerData.getType())) {
        dealTracerLog(tracerData.getTempLogs());
    } else {
        dealFilterModel(tracerData.getTracerBeanList());
    }
}

/**
 * 处理中途日志
 */
private void dealTracerLog(List<RunLogMessage> tempLogs) {
    if(tempLogs==null){
        return;
    }
    for (RunLogMessage runLogMessage :tempLogs) {
        Map<String, Object> map = new HashMap<>(12);
        map.put("tracerId", runLogMessage.getTracerId());
        map.put("className", runLogMessage.getClassName());
        map.put("threadName", runLogMessage.getThreadName());
        map.put("methodName", runLogMessage.getMethodName());
        map.put("logLevel", runLogMessage.getLogLevel());
        map.put("createTime",  formatLongTime(runLogMessage.getCreateTime()));
        map.put("content", runLogMessage.getContent());
        map.putAll(runLogMessage.getTagMap());
        tracerLogToDbStore.offer(map);
    }
}

/**
 * 处理filter里处理的出入参
 */
private void dealFilterModel(List<TracerBean> tracerList) {
    if(tracerList==null){
        return;
    }
    for(TracerBean tracerModel:tracerList){
        if(tracerModel.getResponseContent()==null){
            tracerModel.setResponseContent(DEFAULT_BYTE);
        }
        tracerModel.setCreateTime(formatLongTime(tracerModel.getCreateTimeLong()));
        Map map = new HashMap(BeanMap.create(tracerModel));
        map.remove("createTimeLong");
        tracerModelToDbStore.offer(map);
    }
}

private static String formatLongTime(long time) {
    return DEFAULT_FORMATTER.format(LocalDateTime.ofInstant(Instant.ofEpochMilli(time),ZoneId.systemDefault()));
}

其中TracerLogToDbStore#offer​和

TracerLogToDbStore#offer
/**
 * 写入队列
 */
public void offer(Map<String, Object> map) {
    boolean success = logQueue.offer(map);
    //如果队列已满,则做其他处理
    if (!success) {

    }
}

TracerModelToDbStore#offer
/**
 * 写入队列
 */
public void offer(Map<String, Object> map) {
    boolean success = modelQueue.offer(map);
    //如果队列已满,则做其他处理
    if (!success) {

    }
}
  1. 先对bytes数组进行解压

  2. 然后再反序列化

  3. 根据type​的类型,如果是trade则调用dealTracerLog​方法交给tracerLogToDbStore​处理。如果是SPAN​则调用dealFilterModel​方法交给tracerModelToDbStore​处理。

    1. ​tracerLogToDbStore​的处理逻辑也就是将数据转化为map然后放到logQueue​队列中。

    2. ​tracerModelToDbStore​的处理逻辑也是将数据转化为map然后放到modelQueue​队列中

    • 这里多插入一句,我们会发现map的content就包含了很多数据,只有conteng就够了,为什么还要其他字段呢?实际上其他字段是为了查询方便。因为consumer收到的只是byte数组,这个数据不利于条件查询,所以这里先将其解压和反序列化后,提取出可能查询的字段,再转化为map后入库。

我们简单来看一下谁来消费logQueue​,而modelQueue​同理,我们就不看了

在worker.Starter#start​方法,我们看到方法上面的注解标了@PostConstruct​。

方法逻辑为

@PostConstruct
public void start() {

    logger.info("netty server监听已开启");
    new Thread(() -> {
        //开启服务监听
        udpServer.startServer();
    }).start();

    //入库
    tracerModelToDbStore.beginIntoDb();
    tracerLogToDbStore.beginIntoDb();

    //上报自己ip到配置中心
    centerStarter.uploadSelfInfo();
}

其中有这样一行代码

tracerModelToDbStore.beginIntoDb();
/**
 * 入库
 */
public void beginIntoDb() {
    //初始化队列长度
    modelQueue = new LinkedBlockingQueue<>(preDbSize);
    int pool = Integer.valueOf(poolSize);

    for (int i = 0; i < pool; i++) {
        AsyncPool.asyncDo(() -> {
            try {
                Thread.sleep(new Random().nextInt(8000));
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
            while (true) {
                try {
                    List<Map<String, Object>> tempModels = new ArrayList<>();
                    //每1s入库一次
                    AsyncWorker.drain(modelQueue, tempModels, Integer.valueOf(batchSize), interval, TimeUnit.SECONDS);
                    if (CollectionUtil.isEmpty(tempModels)) {
                        continue;
                    }

                    //批量插入
                    int successCount = db.insertAll("tracer_model", tempModels);
                    totalInsertCount.add(successCount);
                    logger.info("model成功入库 " + tempModels.size() + " 条, 累计已入库 " + totalInsertCount.longValue() + ", 待入库队列size " + modelQueue.size());

                } catch (Exception e) {
                    e.printStackTrace();
                }
            }
        });
    }

}

这里可以看到,异步线程死循环从modelQueue​中取出数据,调用db插入。所以可以看到,最终数据是要落库的,写入clickhouse库。

记住,这里落入DB的数据是什么样的?是压缩后的还是压缩前的呢?

其实,我们回忆一下,HttpFilter将数据的request和response压缩后结合其他字段一起写入netty。netty进行序列化和压缩后发给worker。worker的consumer进行解压缩和反序列化,所以这时候得到的数据,其实就是request和response被压缩,同时还结合其他字段一起的数据。

记住这一点,下面我们来看一下Dashboard的相关逻辑。

dashboard

我们来查看TracerController#detail​方法

/**
 * 详情页
 */
@GetMapping("/detail")
public String detail(@RequestParam("id") String traceId,
                        @RequestParam("uid") String uid,
                        @RequestParam("createTime") String createTime,
                        ModelMap mmap) throws Exception {

    //加synchronized,保证Calendar不出错
    String beginTime = DateUtils.addAndSubtractTime(createTime, -5000L);
    String endTime = DateUtils.addAndSubtractTime(createTime, 5000L);
    //查询数据
    Map<String, Object> map = tracerService.findOne(traceId, uid, beginTime, endTime);

    //转化其中被压缩的response
    String response = map.get("responseContent").toString();
    String resp = ZstdUtils.decompress(response.getBytes(StandardCharsets.ISO_8859_1));
    map.put("responseContent", resp);

    //转化其中被压缩的body
    try {
        String req = map.get("requestContent").toString();
        String re = ZstdUtils.decompress(req.getBytes(StandardCharsets.ISO_8859_1));
        map.put("requestContent", re);
    } catch (Exception e) {
        logger.info("TracerController.detail", e);
    }

    //转为结果类
    TracerVO tracerVO = new TracerVO();
    BeanUtils.populate(tracerVO, map);
    //存入返回模板值
    mmap.put("tracerVO", tracerVO);
    //logger.info(new String(zstd));

    return "tracer/detail";
}

该代码调用tracerService#findOne​方法从DB中读出数据,数据是一个map,然后将requestContent​和responseContent​两个字段进行解压,然后组装成TracerVO​返回给端上,和我们前面介绍的写入DB逻辑正好是逆向过程,完全符合。