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

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的整体服务;确认线上节点都存在风险点,但极少触发到,那么可以使用临时方案从表层去处理已知问题,留下必要的时间深度分析制定方案。

赞(0)
未经允许不得转载:运维军团 » 自建CDN实战经验合集之分片缓存引发的bug

评论 抢沙发

*

  • 昵称 (必填)
  • 邮箱 (必填)
  • 网址