作者｜Eaton

导语｜ 记日志可以说是程序猿/媛日常开发中的家常便饭了。在日常业务场景中，经常需要分析特定用户的日志，一般的日志记录方式很难满足需求，有什么解决办法呢？TARS 框架中包含染色日志的功能，能够记录特定用户的日志，优雅地解决这一问题。本文将会介绍染色日志的原理和功能，以及如何在 TARS 中使用染色日志。

目录

• 背景
• 初识染色日志
• TARS 染色功能概述
• 染色日志初体验
  • 主动打开染色日志
  • 被动打开染色日志
  • 添加特定逻辑
• 总结

背景

很多业务场景中，需要对特定用户的行为进行追踪，比如部分用户反馈服务有 BUG，需要排查，但发现只是个例，要单独找出这些用户的日志进行分析；又或是 APP 上线了一个新的功能，先对一部分用户开放进行测试，需要追踪这部分用户的行为等。

按照一般方式，要在已经记录的日志中检索这部分用户的日志。看起来挺简单，但是在微服务的大背景下，服务间调用关系复杂（如下图），日志分散在各个服务节点上。对于一次调用，需要先获取调用链，再找出具体服务调用的节点，然后从节点上获取日志，这个过程非常繁琐。

另外，日志的记录会消耗程序的性能，占用用户的计算资源。因此在正式环境中，日常业务都会控制日志打印的量，确保日志打印不影响用户服务。而在对特定用户行为进行分析时，往往需要记录额外的日志，才能满足分析等需求，直接增加日志的打印显然不太现实。

可见，传统的日志记录方式无法满足对特定用户行为的日志记录，染色日志就是来解决这一问题的。

初识染色日志

什么是染色日志呢？在一个调用链里面，标志出某个特定需求的过程，让整个调用链里的上下文信息一直被传输下去，就像一开始被标记染色一样，这种标记日志的方式，我们叫它染色日志。

简单来说，就是我们只想要某几个用户的日志信息，通过染色日志把这几个用户的日志另外打印一份，并收集在同一个地方，这样我们在一个地方就能查找到这些染色用户的日志。

我们可以用染色日志定位一些特定的位置，也可以定一些特定的逻辑。比如某微信用户反馈语音发送存在问题，通过对用户ID（微信号）进行染色，后端服务接收到染色用户的请求后，就会将该用户本次调用的处理过程日志打印出来，可以非常方便地获取我们需要的关键信息。除了打印日志，还可以通过染色执行特定逻辑，比如新上线一个功能，开放给一部分用户使用，通过染色，后端服务可以判断用户是否在测试名单中，再执行相应的服务逻辑。

TARS 染色功能概述

TARS 框架支持染色日志功能，可以在某服务某接口中对特定用户号码的消息进行染色，方便地实时察看该用户引起后续所有相关调用消息流的日志。下图为 TARS 中的染色流程

染色日志打开后，在业务中通过指定染色的 key 值，例如指定 QQ 号为 123456 的用户，后续该用户的请求都会在框架中被自动染色，并通过日志服务（tarslog）集中打印染色日志。

我们只需要到 tarslog 服务所在的服务器上查看相应的染色日志即可，具体的路径一般为

/usr/local/app/tars/remote_app_log/tars_dyeing/dyeing/

该目录下一般包含两种日志文件：染色的滚动日志和染色的按天日志，日志文件名格式分别为 tars_dyeing.dyeing_roll_yyyymmdd.log, tars_dyeing.dyeing_day_yyyymmdd.log，比如：

# 染色滚动日志
tars_dyeing.dyeing_roll_20201103.log
# 染色按天日志
tars_dyeing.dyeing_day_20201103.log

滚动日志是服务的本地日志，一般用于记录服务调试信息；按天日志是服务的远程日志，一般用于记录重要的业务信息。开启染色后，如果接收到染色的请求，两种日志都会额外打印一份到 tarslog，只记录染色请求打印的日志，每天保存一个文件。

关于滚动日志和按天日志的用法以及更多信息，可以看到官方文档中日志部分，这里不再赘述。

染色日志初体验

TARS 框架的染色日志有主动打开和被动打开两种方式。接下来让我们通过实例，了解如何通过这两种方式在 TARS 中使用染色日志。本章中使用的实例源码都可以在这里找到。

主动打开染色日志

主动打开，指的是在发起请求的客户端的业务代码中，主动打开框架的染色日志开关。具体流程如下：

1. 在客户端程序适当的地方声明染色日志开关 tars::TarsDyeingSwitch 的对象。
2. 调用该开关对象的 enableDyeing 方法即可打开染色日志。被调用的服务也会自动打开染色开关，并打印日志到 tarslog。如果该被调服务还要调用其他服务，则自动传递给下个服务。
3. 在染色日志开关关闭前，客户端打印的所有日志和被调用的服务打印的日志，都会额外打印一份到日志服务 tarslog。
4. 客户端开关对象析构，染色日志关闭，后续的调用和日志打印不再生成染色日志。

下面，我们通过一个实例来了解如何在客户端（主调方）中主动打开染色日志。

实例

这里以 C++ 为例，按照刚才介绍的流程，开启染色日志并调用 TARS 服务。

在开始之前，我们需要先准备一个 TARS 服务，供之后的客户端调用，源码见 TestServer 源码。我们创建一个服务，应用名为 TestApp，服务名 TestServer，Obj 名为 Test，Test.tars 文件中定义的接口如下

module TestApp
{

interface Test
{
    int test(string id, out string output);
};

};

TestImp.h 和 TestImp.cpp 中 test 接口的定义和实现如下

// TestImp.h
virtual int test(const std::string &id, std::string &output, tars::TarsCurrentPtr current);

//TestImp.cpp
int TestImp::test(const std::string &id, std::string &output, tars::TarsCurrentPtr current)
{
    // 打印本地日志
    TLOGDEBUG(__FILE__ << "|" << __LINE__ << "|" << "id: " << id << endl);
    output = id;
    return 0;
}

构建该服务并在 TarsWeb 上部署发布即可。

关于 TARS 服务的创建与部署，参考文档 TARS 开发入门，这里不再赘述。

接下来，我们编写一个简单的客户端 Demo，完成打开染色日志、调用 TARS 服务接口的流程，如下

#include <iostream>
#include <string>

#include "servant/Communicator.h"
#include "servant/TarsLogger.h"
#include "util/tc_option.h"
#include "util/tc_file.h"

#include "Test.h"

using namespace std;
using namespace tars;

int main(int argc,char ** argv)
{
    try
    {   // 初始化通信代理，用于调用服务
        CommunicatorPtr comm = new Communicator();
        comm->setProperty("locator", "tars.tarsregistry.QueryObj@tcp -h 192.168.0.121 -p 17890 -t 10000");
        TarsRollLogger::getInstance()->setLogInfo("TestApp", "TestServer", "./log", 100000, 10, comm, "tars.tarslog.LogObj");
        TarsRollLogger::getInstance()->sync(false);
        TarsTimeLogger::getInstance()->setLogInfo(comm, "tars.tarslog.LogObj", "TestApp", "TestServer", "./log");

        {   // 在打开染色日志之前，打印日志，这条日志只会打印到本地日志中。
            TLOGDEBUG     (__FILE__ << "|" << __LINE__ << "|" << "Test Before Dyeing" << endl);
            DLOG        << __FILE__ << "|" << __LINE__ << "|" << "D/Test Before Dyeing" << endl;
        }

        {   // 声明一个染色日志开关对象
            TarsDyeingSwitch dye;
            // 打开染色日志
            dye.enableDyeing();

            /* 在打开染色日志之后，打印日志，会在本地日志和染色日志中看到
             * TLOGDEBUG: 打印本地 DEBUG 日志
             *      DLOG: 打印按天的远程日志
             */
            {
                TLOGDEBUG(__FILE__ << "|" << __LINE__ << "|" << "Test After Dyeing" << endl);
                DLOG   << __FILE__ << "|" << __LINE__ << "|" << "D/Test After Dyeing" << endl;
            }

            // 生成调用代理
            TestApp::TestPrx prx = comm->stringToProxy<TestApp::TestPrx>("TestApp.TestServer.TestObj");
            string output;
            // 调用 test 接口
            prx->test("hello", output);
            cout << output << endl;
        }

        //染色日志开关已经析构，染色功能失效，以后的日志不会打印到染色日志中
        TLOGDEBUG(__FILE__ << "|" << __LINE__ << "|" << "~Dyeing" << endl);
        DLOG   << __FILE__ << "|" << __LINE__ << "|" << "D/~Dyeing" << endl;
    }
    catch(exception& e)
    {
        cerr << "exception:" << e.what() << endl;
    }
    catch (...)
    {
        cerr << "unknown exception." << endl;
    }
    sleep(10); // 等待异步写日志线程同步日志数据到 logserver
    return 0;
}

可以看到，该客户端中包含了三次日志打印，只有一次在染色日志开启期间打印。同时，染色日志开启期间，调用了服务 TestApp.TestServer.TestObj 的接口 test。

编译并执行客户端后，我们就可以在日志服务所在服务器的路径 /usr/local/app/tars/remote_app_log/tars_dyeing/dyeing/ 中，找到染色日志文件，如 tars_dyeing.dyeing_roll_20201104.log 和 tars_dyeing.dyeing_day_20201104.log。

• tars_dyeing.dyeing_roll_20201104.log

  使用TLOGDEBUG打印的滚动日志

  192.168.0.121|TestApp.TestServer|2020-11-04 03:56:53|139734968739712|DEBUG|main.cpp|37|Test After Dyeing

• tars_dyeing.dyeing_day_20201104.log

  使用DLOG打印的远程日志

  192.168.0.121|TestApp.TestServer|2020-11-04 03:56:53|main.cpp|38|D/Test After Dyeing

可以看出，染色日志文件中，只有在 TarsDyeingSwitch dye 作用域内打印的日志。

有兴趣的读者可以下载客户端源码自行尝试，将其中的 IP 替换为自己服务所在节点的 IP 即可。

被动打开染色日志

被动打开，指的是在请求的服务端预先设定染色的条件，判断传递的 key 值，由服务端来打开自身的染色日志开关，相比于主动打开的方式，被动打开不需要修改客户端(调用方)业务代码，是一种非侵入式的方式。具体流程如下：

1. 在 tars 接口文件中，通过 routekey 来设置接口的某个参数为 key，如用户 ID；
2. 在 TarsWeb 通过框架命令传入需要染色的用户ID的值以及服务 Obj 和接口名；
3. 服务收到匹配的请求后，对请求包进行染色处理，并打印日志到日志服务 tarslog；
4. 服务处理过程如果继续调用其他 TARS 服务，则自动传递给下个服务。

接下来我们通过一个实例，了解如何通过被动方式打开染色日志。

实例

• 将接口 test 的参数 id 设置为染色 key

这里我们继续使用前面创建的 TARS 服务 Demo。在 tars 接口文件中，修改接口 test，使用 routekey 指定其中的参数 id 为染色 key，如下

    int test(routekey string id, out string output);

接着，替换客户端(调用方)原本使用的 tars 文件并重新编译构建就完成了客户端的修改，无需修改业务代码。

• 开启染色日志并设置需要染色的 key 值（test 中 id 的值）

TARS 框架中预设了一些框架命令，能够通过 TarsWeb 平台发送。这里我们可以通过命令 tars.setdyeing 开启染色日志，命令格式如下：

tars.setdyeing dyeingKey dyeingServant [dyeingInterface]

三个参数分别为染色 key 值（routekey 标记的参数，本例为 id），服务对象名称，接口名称（可选）。 例如本文中的服务对象为 TestApp.TestServer.TestObj，染色接口名称为 test，我们想对 id 为 123456 的用户染色，那么可以通过管理平台发布以下命令：

tars.setdyeing 123456 TestApp.TestServer.TestObj test

该命令通过 TarsWeb 页面的 服务管理->更多命令->自定义命令 来发送，如图所示

若后续没有滚动日志输出，可以在此页面设置日志等级为 DEBUG

完成上述步骤，就完成了染色的打开和染色用户ID值的添加。

当接口 test 有 id 为 123456 的请求发到该服务，将会另外打印染色日志，同样保存在日志服务（tarslog）机器的路径 /usr/local/app/tars/remote_app_log/tars_dyeing/dyeing/ 下的滚动日志文件和按天日志文件中。

这里我们可以继续使用上节的客户端，因为不需要在代码中主动声明并打开染色开关，对客户端代码进行精简，保持原有的接口调用逻辑即可，修改后如下

#include <iostream>
#include <string>

#include "servant/Communicator.h"
#include "util/tc_option.h"
#include "util/tc_file.h"

#include "Test.h"

using namespace std;
using namespace tars;

int main(int argc,char ** argv)
{
    try
    {   // 初始化通信代理，用于调用服务（读者无需关注）
        CommunicatorPtr comm = new Communicator();
        comm->setProperty("locator", "tars.tarsregistry.QueryObj@tcp -h 192.168.0.121 -p 17890 -t 10000");

        // 生成调用代理
        TestApp::TestPrx prx = comm->stringToProxy<TestApp::TestPrx>("TestApp.TestServer.TestObj");
        string output;
        // 调用 test 接口, 传入染色id: 123456
        prx->test("123456", output);
        cout << output << endl;
        // 调用 test 接口, 传入非染色id: tars
        prx->test("tars", output);
        cout << output << endl;
    }
    catch(exception& e)
    {
        cerr << "exception:" << e.what() << endl;
    }
    catch (...)
    {
        cerr << "unknown exception." << endl;
    }
    return 0;
}

参考客户端源码

编译执行后，我们可以在染色日志文件中，例如 tars_dyeing.dyeing_roll_20201104.log

192.168.0.121|TestApp.TestServer|2020-11-04 15:58:08|140356905592576|DEBUG|TestImp.cpp|31|id: 123456

添加特定逻辑

前面我们提到过，能够在服务中为染色的用户添加特定的逻辑，接下来将继续以 TestServer 为例，介绍如何为染色用户添加特定逻辑。

实现方式其实很简单：通过判断传入的请求是否为染色请求，决定是否执行特定的逻辑即可。例如，我们在 TestImp.cpp 中修改 TestServer 接口的实现，如果当前用户是染色用户则输出 Dyeing is on，普通用户则输出用户 id，代码如下

 int TestImp::test(const string &id, string &output, tars::TarsCurrentPtr current)
{   // 服务对象名
    string servantName =  ServerConfig::Application + "." + ServerConfig::ServerName + ".TestObj";

    // 判断是否为染色用户
    if (tars::ServantHelperManager::getInstance()->isDyeingReq(id, servantName, "test")) {
        // 染色用户返回值
        output = "Dyeing is on";
        TLOGDEBUG(__FILE__ << "|" << __LINE__ << "|" << "Test"  << endl);
        DLOG   << __FILE__ << "|" << __LINE__ << "|" << "D/Test"  << endl;
        return 0;
    }
    // 非染色用户返回用户 id
    output = id;
    TLOGDEBUG(__FILE__ << "|" << __LINE__ << "|" << "Test" << endl);

    return 0;
}

上述代码中，我们使用 ServantHelperManager 中的 isDyeingReq 来判断请求 ID 是否染色，染色则返回 true，并在 if 中添加对染色用户执行的逻辑。isDyeingReq 需要传入三个参数，routekey 标识的入参值(id)，服务对象名(TestApp.TestServer.TestObj)和接口名称(test)。

接下来，我们直接使用上一节的客户端实例，其中包含了两次接口调用

...
        // 调用 test 接口, 传入染色id: 123456
        prx->test("123456", output);
        cout << output << endl;
        // 调用 test 接口, 传入非染色id: tars
        prx->test("tars", output);
        cout << output << endl;
...

前面我们已经在 TarsWeb 平台开启了对 123456 的染色，没有开启对 tars 的染色，编译并执行该客户端，结果如下

Dyeing is on
tars

可见 id 为 123456 的请求成功触发染色逻辑，而 id 为 tars 的请求没有。

总结

染色日志填补了传统日志记录方式的不足，通过类似染色的方式，实现了对特定用户、调用链日志的集中打印，方便日志的查看和分析。TARS 框架包含了染色功能，并提供了主动与被动两种打开染色日志的方式，方便用户根据需求选择。同时，还能为特定的请求添加额外的特定逻辑，进一步扩大使用场景，如灰度发布等。

TARS 可以在考虑到易用性和高性能的同时快速构建系统并自动生成代码，帮助开发人员和企业以微服务的方式快速构建自己稳定可靠的分布式应用，从而令开发人员只关注业务逻辑，提高运营效率。多语言、敏捷研发、高可用和高效运营的特性使 TARS 成为企业级产品。

TARS微服务助您数字化转型，欢迎访问：

TARS官网：https://TarsCloud.org

TARS源码：https://github.com/TarsCloud

Linux基金会官方微服务免费课程：https://www.edx.org/course/building-microservice-platforms-with-tars

获取《TARS官方培训电子书》：https://wj.qq.com/s2/6570357/3adb/

或扫码获取：