分布式链路追踪系统 - Jaeger在flask/django中的使用

一时失言乱红尘 2022-11-05 12:57 94阅读 0赞

# 链路追踪 #

分布式链路追踪，也称为分布式请求追踪，是一种用于分析和监视应用程序的方法，特别是那些使用微服务体系结构构建的应用程序; 分布式追踪有助于查明故障发生的位置以及导致性能低下的原因，开发人员可以使用分布式跟踪来帮助调试和优化他们的代码。

链路追踪系统核心步骤一般有三个：代码埋点，数据存储、查询展示。

在数据采集过程，需要侵入用户代码做埋点，不同系统的API不兼容会导致切换追踪系统需要做很大的改动。为了解决这个问题，诞生了opentracing 规范。

# OpenTracing #

opentracing 是一套分布式追踪协议，与平台，语言无关，统一接口，方便开发接入不同的分布式追踪系统。

*  语义规范 : 描述定义的数据模型 Tracer，Sapn 和 Span Context 等；
 *  语义惯例 : 罗列出 tag 和 logging 操作时，标准的key值；

## Trace 和 span ##

opentracing 中的 Trace（调用链）通过归属此链的 Span 来隐性定义。

*  Trace 事物在分布式系统中移动时的描述， 一条 Trace 可以认为一个有多个 Span 组成的有向无环图（DAG图）。
 *  Span 是一种命名的、定时的操作，是一个逻辑执行单元，Spans接受key:value标签以及附加到特定Span实例的细粒度、带时间戳的结构化日志。
 *  Span Contenxt 携带分布式事务的跟踪信息，包括当它通过网络或消息总线将服务传递给服务时。

Trace通过传递 Span Context 来提供足够的信息建立 span 间的关系。

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center]  
下图是由8个Spans构成的一个Trace

[Span A]  ←←←(the root span)
                |
         +------+------+
         |             |
     [Span B]      [Span C] ←←←(Span C is a `ChildOf` Span A)
         |             |
     [Span D]      +---+-------+
                   |           |
               [Span E]    [Span F] >>> [Span G] >>> [Span H]
                                           ↑
                                           ↑
                                           ↑
                             (Span G `FollowsFrom` Span F)

使用时间轴来可视化展示Trace

––|–––––––|–––––––|–––––––|–––––––|–––––––|–––––––|–––––––|–> time
    
     [Span A···················································]
       [Span B··············································]
          [Span D··········································]
        [Span C········································]
             [Span E·······]        [Span F··] [Span G··] [Span H··]

## Inject 和 Extract 操作 ##

在单体程序中, 父子Span通过Span Context关联, 而Span Context是在内存中的, 显而易见这样的方法在跨应用的场景下是行不通的。

跨应用跨进程通讯使用的方式通常是"序列化"，在jaeger-client-python库中也是通过类似的操作去传递信息, 它们叫:Tracer.inject() 与 Tracer.extract()。

当客户端发起http通信时候，当前进程调用Tracer.inject(…)注入当前活动的Span Context以及其他相关参数，通常客户端可以将该Span Context以 http 的 headers 参数(trace\_id)的方式标识传递， 服务进程调用Tracer.extract(…)，从传入的请求的headers中抽取从上面注入的Span Context和参数还原上下文。

# Jaeger #

Jaeger (ˈyā-gər) 是Uber开发的一套分布式追踪系统，实现了opentracing的规范，对Tracer与Span等接口写了自己的实现，是CNCF的开源项目。

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 1]

*  Client - 应用程序通过 API 写入数据，client library 把 trace 信息按照应用程序指定的`采样策略`传递给 jaeger-agent。
 *  Agent - 是一个监听在 UDP 端口上接收 span 数据的网络守护进程，它会将数据批量发送给 collector。  
    它被设计成一个基础组件，推荐部署到所有的宿主机上。Agent 将 client library 和 collector 解耦，为 client library 屏蔽了路由和发现 collector 的细节。
 *  Collector - 接收 jaeger-agent 发送来的数据，然后将数据写入后端存储。  
    Collector 被设计成无状态的组件，因此您可以同时运行任意数量的 jaeger-collector。
 *  Data Store - 后端存储被设计成一个可插拔的组件，支持将数据写入 cassandra、elastic search。
 *  Query - 接收查询请求，然后从后端存储系统中检索 trace 并通过 UI 进行展示。  
    Query 是无状态的，您可以启动多个实例，把它们部署在 nginx 这样的负载均衡器后面。

官方释放部署的镜像到 dockerhub，所以部署 jaeger 非常方便，如果是本地测试，可以直接用 jaeger 提供的 all-in-one 镜像部署（上报的链路数据保存在本地内存，所以只能用于测试）。

# 追踪实践 - flask/django #

[github demo(jaeger in flask/django)][github demo_jaeger in flask_django]

jaeger api链路追踪使用流程：

*  1.应用启动创建全局的Tracer
 *  2.请求进入时提取（或生成）链路信息，提取Parent Span（或生成Root Span）和上下文，打上相关tag
 *  3.请求结束后添加相关tag和日志，并提交Span信息

## 构建全局Tracer（单例模式） ##

根据opentracing的规范，每个服务建议只有一个Tracer。

jaeger默认使用header的`uber_trace_id`传递链路标识，此处默认使用`trace_id`标识

# coding: utf-8
    
    import six
    
    from jaeger_client import Config
    
    # Name of the HTTP header used to encode trace ID
    DEFAULT_TRACE_ID_HEADER = 'trace_id' if six.PY3 else b'trace_id'
    
    
    def init_tracer(service_name: str, config: dict):
        """
        initialize the global tracer
        :param service_name:
        :param config:
        :return:
        """
        assert isinstance(config, dict)
        # default use `trace_id` replace jaeger `uber-trace-id`
        config['trace_id_header'] = config.get('trace_id_header',
                                               DEFAULT_TRACE_ID_HEADER)
    
        config = Config(config=config, service_name=service_name, validate=True)
    
        # this call also sets opentracing.tracer
        return config.initialize_tracer()

## 请求进入时提取（或生成）链路信息，提取Parent Span（或生成Root Span）和上下文，打上相关tag ##

def before_request_trace(tracer, request, view_func):
        """
        Helper function to avoid rewriting for middleware and decorator.
        Returns a new span from the request with logged attributes and
        correct operation name from the view_func.
        """
        # strip headers for trace info
        headers = format_request_headers(request.META)
    
        # start new span from trace info
        operation_name = view_func.__name__
        try:
            span_ctx = tracer.extract(opentracing.Format.HTTP_HEADERS, headers)
            scope = tracer.start_active_span(operation_name, child_of=span_ctx)
        except (opentracing.InvalidCarrierException,
                opentracing.SpanContextCorruptedException):
            scope = tracer.start_active_span(operation_name)
    
        span = scope.span
        span.set_tag(tags.COMPONENT, 'Django')
        span.set_tag(tags.TRACE_ID, format_hex_trace_id(span.trace_id))
        span.set_tag(tags.SPAN_KIND, tags.SPAN_KIND_RPC_SERVER)
        span.set_tag(tags.HTTP_METHOD, request.method)
        span.set_tag(tags.HTTP_URL, request.get_full_path())
    
        request_id = headers.get(tags.REQUEST_ID)
        if request_id:
            span.set_tag(tags.REQUEST_ID, request_id)
    
        request.scope = scope
    
        return scope

## 请求结束后添加相关tag和日志，并提交Span信息 ##

def after_request_trace(request, response=None, error=None):
        scope = getattr(request, 'scope', None)
    
        if scope is None:
            return
    
        if response is not None:
            scope.span.set_tag(tags.HTTP_STATUS_CODE, response.status_code)
        if error is not None:
            scope.span.set_tag(tags.ERROR, True)
            scope.span.log_kv({
                'event': tags.ERROR,
                'error.kind': type(error),
                'error.object': error,
                'error.stack': error.__traceback__,
                'request.headers': format_request_headers(request.META),
                'request.args': request.GET,
                'request.data': request.POST
            })
    
        scope.close()

## 链路追踪装饰器 ##

def trace(tracer):
        """
        Function decorator that traces functions such as Views
        """
        def decorator(view_func):
            def wrapper(request, *args, **kwargs):
                before_request_trace(tracer, request, view_func)
                try:
                    response = view_func(request, *args, **kwargs)
                except Exception as e:
                    after_request_trace(request, error=e)
                    raise e
                else:
                    after_request_trace(request, response)
    
                return response
    
            wrapper.__name__ = view_func.__name__
            return wrapper
    
        return decorator

## django链路追踪中间件 ##

class OpenTracingMiddleware(MiddlewareMixin):
        def __init__(self, get_response=None):
            """
             __init__() is only called once, no arguments, when the Web server
            responds to the first request
            """
            self._init_tracer()
            self.get_response = get_response
    
        def _init_tracer(self):
            """
            get global tracer callable function from Django settings.
            :return:
            """
            assert settings.SERVICE_NAME
            assert settings.OPENTRACING_TRACER_CONFIG
    
            self.tracer = init_tracer(settings.SERVICE_NAME,
                                      settings.OPENTRACING_TRACER_CONFIG)
    
        def process_view(self, request, view_func, view_args, view_kwargs):
            before_request_trace(self.tracer, request, view_func)
    
        def process_exception(self, request, exception):
            after_request_trace(request, error=exception)
    
        def process_response(self, request, response):
            after_request_trace(request, response=response)
            return response

## 追踪ERROR级别日志 ##

# coding: utf-8
    import datetime
    import logging
    from logging import Handler
    
    import opentracing
    
    from tracing import tags
    
    
    class ErrorTraceHandler(Handler):
        """
        Custom ErrorTraceHandlerimplementation to forward python logger records to Jaeger / OpenTracing
        """
        def __init__(self, level=logging.ERROR):
            """
            Initialize the handler.
            """
            super().__init__(level)
    
        def emit(self, record):
            try:
                msg = self.format(record)
                operation_name = 'logger[{}]'.format(record.name)
                parent_span = opentracing.tracer.active_span
                if not parent_span:
                    return
                with opentracing.tracer.start_span(operation_name, child_of=parent_span) as logger_span:
                    logger_span.set_tag(tags.SPAN_KIND, tags.SPAN_KIND_LOG)
                    logger_span.set_tag(tags.LOGGER, record.name)
    
                    logger_span.log_kv({
                        'event': tags.LOG_ERROR,
                        'message': msg,
                        'log.stack_info': record.stack_info,
                        'log.asctime': getattr(record, 'asctime', datetime.datetime.now()),
                        'log.created': record.created,
                        'log.filename': record.filename,
                        'log.funcName': record.funcName,
                        'log.levelname': record.levelname,
                        'log.lineno': record.lineno,
                        'log.module': record.module,
                        'log.msecs': record.msecs,
                        'log.name': record.name,
                        'log.pathname': record.pathname,
                        'log.process': record.process,
                        'log.thread': record.thread
                    })
            except Exception as e:
                self.handleError(record)

## 通过 http://localhost:16686 可以在浏览器查看 Jaeger UI ##

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 2]  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 3]  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 4]  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 5]  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 6]

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 7]

## QA ##

### `<trace-without-root-span>` ###

这个错误原因是: B span 是归属于 A span的, 但Jaeger服务器只收集到了B span, 但没有收集到父级A span, 这时候B span就是一个 without-root-span.

可能原因有下:

*  A 忘记调用scope.close()
 *  A 在程序退出时没有调用close(), 这会导致缓冲区的spans没有被push到服务器
 *  等待一段时间, 缓冲区Span会经过一段时间才会被Push到服务器
 *  发送的Spans个数大于了QueueSize, 多余QueueSize的Spans可能会被丢弃,

### `有时候Jaeger上有数据, 有时候没有` ###

由于客户端和Jaeger-Agent之间是通过UDP协议传输的, 所以如果测试服务器与Jager-Agent服务之间是外网网络环境, 则可能会导致丢包, 通常包越大越容易丢包.

解决办法是将Agent部署到本机, 不过在开发环境为了方便也可以将客户端配置使用Jaeger-Collector, 这时会使用HTTP协议发送Spans.

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center]: /images/20221023/b6ac07ad519142b6991556542411c740.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 1]: /images/20221023/d56da812dbd14040819a1b07e4274ae8.png
[github demo_jaeger in flask_django]: https://github.com/pushiqiang/jaeger_flask_django
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 2]: /images/20221023/6c1ab9f794da410cb0cb4a6dc9c69c37.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 3]: /images/20221023/5beebf9f92154eb38503efc4646c31ac.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 4]: /images/20221023/790848bf19e048b49227d7da190f27cf.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 5]: /images/20221023/358a7433d63f4a2ea02b22760e7ddffc.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 6]: /images/20221023/a48c50f7d48047a2b9acaf8e773d5840.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3B1c2hpcWlhbmc_size_16_color_FFFFFF_t_70_pic_center 7]: /images/20221023/79931d615e6e472281d62a2e3937add6.png