IT博客汇 | 自建CDN实战经验合集之分片缓存引发的bug

自建CDN实战经验合集之分片缓存引发的bug

admin发表于 2023-02-25 03:41:37

1 背景

在线上业务中，为了降低大文件的回源压力和硬盘IO压力，提升CDN的下载体验，通常会开启分片缓存。我们自建CDN基于nginx ngx_http_slice_module模块和trafficserver cache_range_requests插件实现分片缓存，可阅读该篇文章了解一波自建CDN实战经验合集之一种实现分片缓存方式的探讨。

然而，有一天”文件错误”的业务打点在某一区域突然增多！

真的有问题吗？会不会是自然量上升引起的“错误”正相关？会不会是节点刷新任务异常？关子就不卖了，毕竟标题就写了，下面分享下我们团队排查分析的历程，和解决方案。

2 异常存在，及时止损

“错误反馈”一般和自然量呈正相关，比如当天请求量增大很多，虽然错误比例波动不大，但异常绝对值会有增加。我们从环比带宽排除了该因素。

难道是节点刷新任务异常？相应监控无告警，期间无刷新任务，也排除该因素。

那真的有问题吗？日志是不会说谎的，查找出对应的URL，指定对应的节点请求，文件确实错误，且能复现多个异常上报的URL，那么证明这个节点存在异常。

在验证其他CDN节点响应正常后，立马进行调度调整，剔除异常响应点，及时止损，保障CDN的整体服务。

3 原因分析，临时处理

先从下图简单了解下自建CDN的架构：

在对比正常响应的CURL请求和异常响应的CURL请求时，发现HTTP响应头-Content-Length字段有异常，理论上状态码200的无中断响应的Content-Length字段值是文件大小，但该值却是1048576，和域名配置的分片缓存大小一致

异常头< Content-Length: 1048576 
正常头< Content-Length: 45947398

再回顾下节点的nginx日志和回源链路的日志，发现回源链路的日志是正常的，但节点nginx日志有异常，ats响应给nginx第一个分片的Content-Range头的总长度值，异常变成了第一个分片的长度，导致nginx误解第一个分片就是完整响应，客户端收到后，文件校验自然是不通过的。

以黑盒视角从用户侧出发，域名绑定异常节点，请求对应的URL，异常复现，并有”文件错误”的业务打点。确定了该异常的特征，本文使用bug-CR进行标记。

bug-CR无论何时都能稳定复现，说明缓存的内容有问题；当清除该缓存后（删除刷新）再次请求，响应则正常。

虽然这个节点不在线上调用了，但其组件和配置与线上其他节点一致，我们认为其他节点也存在风险，只是极少触发到(<0.0001%)。短时间无法查明原因，那么就缓解bug带来的影响，临时上线一个自动修复脚本。

1、find #每个节点检查请求的URL，是否content-range字段符合bug现象 
2、purge #针对该URL进行删除刷新

4 深度分析，查询根因

上文我们定位到bug-CR是ats的问题，且可能和分片缓存插件有关，接下来调整相关配置，打印输出debug日志

records.config文件:

#打开debug 
CONFIG proxy.config.diags.debug.enabled INT 1 
#输出http日志和插件日志(cache_process.cc编译) 
CONFIG proxy.config.diags.debug.tags STRING http.*|cache_process

发现异常点，分片缓存插件覆盖添加了一个错误的content-range字段

Server {0x7ff875bdb700} DIAG: (cache_process) [cache_process.cc:700] handle_server_read_response(): add content range header: bytes 0-1048575/1048576

正常响应debug日志与异常响应debug日志进行对比。异常响应的第一次回源总是有异常并重试

DEBUG: (http) [195062] [&HttpSM::handle_server_setup_error, VC_EVENT_ERROR]
…
DEBUG: (http_trans) [retry_server_connection_not_open] attempts now: 2, max: 4

重试成功后，会异常重复calling分片插件

DEBUG: (http) [195062] calling plugin on hook TS_HTTP_READ_RESPONSE_HDR_HOOK at hook 0x16b0a60

状态码修改成200，ats缓存该异常分片并响应，导致CDN节点持续使用异常分片响应用户请求

DEBUG: (http_trans) [hcoofsr] response cacheable 
DEBUG: (http_trans) [hcoofsr] response code: 200 
DEBUG: (http_trans) [hcoofsr] cache write

原代码块

static void
handle_server_read_response(TSHttpTxn txnp, struct txndata *txn_state)
{
TSMBuffer response;
TSMLoc resp_hdr;
TSHttpStatus status;
if (TS_SUCCESS == TSHttpTxnServerRespGet(txnp, &response, &resp_hdr)) {
status = TSHttpHdrStatusGet(response, resp_hdr);
//only when status is 200,and not content-length,then consider it is truncate
if (TS_HTTP_STATUS_OK == status) {
if(get_content_length(txnp, txn_state) == false){
    DEBUG_LOG("warnning. response is not include content_length, attempting to disable cache write.");

    TSHttpHdrReasonSet(response, resp_hdr, "noconlengt",10);

    TSHandleMLocRelease(response, resp_hdr, NULL);
    return;
  }
}

//if stauts is 206,then it is 206 partial content
if (TS_HTTP_STATUS_PARTIAL_CONTENT == status) {

  TSHttpHdrStatusSet(response, resp_hdr, TS_HTTP_STATUS_OK);
  DEBUG_LOG("Set response header to TS_HTTP_STATUS_OK.");
} else if (TS_HTTP_STATUS_OK == status) {
    char *temp = (char *) TSmalloc(255 * sizeof (char));
    if (NULL == temp) {
      DEBUG_LOG("TSmalloc failed");
      TSHandleMLocRelease(response, resp_hdr, NULL);
      return; 
   }

    //for range end > content length
    if(txn_state->content_length != 0 && txn_state->range_end >= txn_state->content_length){
      txn_state->range_end = txn_state->content_length - 1;
    }

    //when range:bytes=xxx-,the end is null,so set range_end=content_length-1
    if(txn_state->content_length != 0 && (txn_state->range_end < 0)){
      txn_state->range_end = txn_state->content_length - 1;
    }
    /*
    1.whether range start or end is negative, valid_range is false,then all return 416;
    2.if invalid range request, valid_range is false, and return 416;
    3.if range start > end, then all return 416;
    4.if start > content_length, then all return 416;
    */
    if(txn_state->valid_range == false || txn_state->range_start > txn_state->range_end || txn_state->range_start>txn_state->content_length){
      //DEBUG_LOG("print log:%ld %ld %ld", txn_state->range_start, txn_state->range_end, txn_state->content_length);
      TSHttpHdrStatusSet(response, resp_hdr, TS_HTTP_STATUS_REQUESTED_RANGE_NOT_SATISFIABLE);
      TSHttpHdrReasonSet(response, resp_hdr, TSHttpHdrReasonLookup(TS_HTTP_STATUS_REQUESTED_RANGE_NOT_SATISFIABLE),
          strlen(TSHttpHdrReasonLookup(TS_HTTP_STATUS_REQUESTED_RANGE_NOT_SATISFIABLE)));
      int len = snprintf(temp, 255 * sizeof (char), "bytes */%ld", txn_state->content_length);
      if (set_header(response, resp_hdr, TS_MIME_FIELD_CONTENT_RANGE, TS_MIME_LEN_CONTENT_RANGE, temp,len)) {
        DEBUG_LOG("add content range header: %s", temp);
      }

      TSfree(temp);
      TSHandleMLocRelease(response, resp_hdr, NULL);
      return;
    }
    else{
      int len = snprintf(temp, 255 * sizeof (char), "bytes %ld-%ld/%ld", txn_state->range_start,txn_state->range_end, txn_state->content_length);
      if (set_header(response, resp_hdr, TS_MIME_FIELD_CONTENT_RANGE, TS_MIME_LEN_CONTENT_RANGE, temp, len)) {
        DEBUG_LOG("add content range header: %s", temp);
      } 
      TSfree(temp);
    }
    transform_add(txnp, txn_state);
}

}
TSHandleMLocRelease(response, resp_hdr, NULL);
}

为什么会重复calling插件呢？当我们尝试分析ats源码时，发现可能需要大量的精力去探索，甚至可能需要修改ats的源码；为了不引入新的变量，以最小的变动解决问题，采用见洞补洞的方式，在

//if stauts is 206,then it is 206 partial content
if (TS_HTTP_STATUS_PARTIAL_CONTENT == status) {
  TSHttpHdrStatusSet(response, resp_hdr, TS_HTTP_STATUS_OK);
  DEBUG_LOG("Set response header to TS_HTTP_STATUS_OK.");
} else if (TS_HTTP_STATUS_OK == status) {

追加

if (txn_state->content_length != 0 && txn_state->range_end + 1 == txn_state->content_length) {
  txn_state->content_length = 0;
  TSHttpHdrStatusSet(response, resp_hdr, TS_HTTP_STATUS_PARTIAL_CONTENT);
  DEBUG_LOG("Set response header to TS_HTTP_STATUS_PARTIAL_CONTENT.");
  TSHandleMLocRelease(response, resp_hdr, NULL);
  return;}

从逻辑图可看出，经补丁修复后，虽然该分片不会被缓存，但该劣势影响甚微。例如一个100MB的文件，若配置是1M分片，遇到bug-CR进行修复时，第一个分片没被缓存，其它99个分片基本都能正常缓存。

5 黑盒压测，验证补丁

复核定位故障组件，bug-CR的触发条件之一：应用ats分片缓存插件

异常响应的第一次ats回源总是ERROR，对比测试回源链路，bug-CR的触发条件之二：回源链路长。回源链路越长，可能抖动越大，触发bug的概率越大。

即触发bug-CR，需同时满足以下2个必要条件：

应用本文所指的ats分片缓存插件
回源链路抖动

压测补丁，补丁能修复bug-CR，达到修复预期；接下来便可制定灰度计划，应用上线了。

6 总结

解决bug-CR的方式可能有多种，例如可尝试升级ats版本，尝试使用官网最新的分片缓存插件等；但CDN组件的升级，并非像手机app升级完后几乎无缝衔接操作。组件升级关联的环境、配置命令、操作命令都会有变化，需要一个相对较长的时间去保证不会引入新的问题。所以从我们的业务场景，CDN使用场景评估，需要一个最小变动方案解决当前问题。给插件打补丁，舍弃一个分片的缓存，换回正确的响应，是最适合我们的解决方案。

本文是从”事后诸葛亮”的角度梳理整个历程，实际上还是走了些弯路，在多次压测多次修改补丁后，才最终明确触发条件和解决方案。整个过程最重要是保证CDN的正常服务，异常存在则要及时止损，保障CDN的整体服务；确认线上节点都存在风险点，但极少触发到，那么可以使用临时方案从表层去处理已知问题，留下必要的时间深度分析制定方案。