分享一次替 Boss 直聘企业端 Debug 的经历

背景

我们是一家做招聘管理系统的公司,产品名叫 OurATS.

我们有一家规模稍大点的客户,这家客户同时也是 Boss 直聘的重度使用者,暂称此客户为 A.

现在的招聘管理系统大多都有一个通过浏览器插件实现的简历查重功能,当 HR 在招聘渠道(比如 Boss 直聘)上看到一份简历后,插件就会对此简历进行查重,如果客户公司简历库中已经有此候选人简历了,就会提示 HR.

Bug 现身

这天客户 A 的多名 HR 反馈说你们的招聘系统 OurATS 用不了了,Chrome 浏览器报 ERR_INSUFFICIENT_RESOURCES.

经过几次远程后,发现一个共性,报这个错的时候,HR 同时都打开了 Boss 直聘.

进一步发现,当 ERR_INSUFFICIENT_RESOURCES 报错出现后,实际上不只是 OurATS 用不了,其它任意网站也都访问不了,比如百度,甚至 Boss 直聘的首页 https://zhipin.com 也一样报错 ERR_INSUFFICIENT_RESOURCES,但此时已经打开的 Boss 直聘企业端后台那个 tab 页没有问题,操作什么的一切正常.

再进一步发现,如果把 Boss 直聘那个 tab 页关掉,那么就能访问 OurATS 了,百度也能访问了.

在复现问题的过程中,还发现,刚打开 Chrome 使用时没有问题,长时间使用后此问题才出现.

初步结论: Boss 直聘企业端后台是一个单页应用,长时间使用后,可能触发了 chrome 浏览器的 bug,导致报 ERR_INSUFFICIENT_RESOURCES.

Boss 甩锅

客户 A 将此情况反馈给 Boss 直聘后,Boss 说这不是我们的问题,是你们用的招聘系统和插件的问题.

客户 A 只能再向我们反馈问题,并且由于出问题时不是 Boss 直聘用不了,而是我们的招聘系统 OurATS 用不了,所以此时各种说法就出现了,比如 Boss 有针对性的封禁了客户 A 使用的 OurATS,再比如 OurATS 的服务器超负荷了什么的.

但我们心里清楚地很,这和我们一毛钱关系都没有呀!

开始 Debug

仅仅从浏览器使用时呈现的现象,已经无法说服客户这是 Boss 直聘的 bug 了.

那接下来要想自证清白,只能从 chromium 源码入手,找出问题的根结.

吭哧吭哧花了两天时间,才下载回来 chromium 源码和编译工具链,又花了一个晚上,才第一次编译完成.

Bug 定位

Visual Studio 打开 chromium 源码目录,搜索 ERR_INSUFFICIENT_RESOURCES,发现有 100 多处,不过有一些是 unittest.

不管三七二十一,直接把所有 return ERR_INSUFFICIENT_RESOURCES 的地方都加上 LOG(ERROR),这样下次再报错就知道是哪里的问题了.

添加 LOG 的过程中,发现下边的代码段最为可疑:

// services/network/url_loader_factory.cc

void URLLoaderFactory::CreateLoaderAndStart(...) {
  // ...
  bool exhausted = false;
  if (!context_->CanCreateLoader(params_->process_id)) {
    exhausted = true;
  }

  int keepalive_request_size = 0;
  if (url_request.keepalive && keepalive_statistics_recorder) {
    const size_t url_size = url_request.url.spec().size();
    size_t headers_size = 0;

    net::HttpRequestHeaders merged_headers = url_request.headers;
    merged_headers.MergeFrom(url_request.cors_exempt_headers);

    for (const auto& pair : merged_headers.GetHeaderVector()) {
      headers_size += (pair.key.size() + pair.value.size());
    }

    keepalive_request_size = url_size + headers_size;

    KeepaliveBlockStatus block_status = KeepaliveBlockStatus::kNotBlocked;
    const auto& top_frame_id = *params_->top_frame_id;
    const auto& recorder = *keepalive_statistics_recorder;

    if (!context_->CanCreateLoader(params_->process_id)) {
      // We already checked this, but we have this here for histogram.
      DCHECK(exhausted);
      block_status = KeepaliveBlockStatus::kBlockedDueToCanCreateLoader;
    } else if (recorder.num_inflight_requests() >= kMaxKeepaliveConnections) {
      exhausted = true;
      block_status = KeepaliveBlockStatus::kBlockedDueToNumberOfRequests;
    } else if (recorder.NumInflightRequestsPerTopLevelFrame(top_frame_id) >=
               kMaxKeepaliveConnectionsPerTopLevelFrame) {
      exhausted = true;
      block_status =
          KeepaliveBlockStatus::kBlockedDueToNumberOfRequestsPerTopLevelFrame;
    } else if (recorder.GetTotalRequestSizePerTopLevelFrame(top_frame_id) +
                   keepalive_request_size >
               kMaxTotalKeepaliveRequestSize) {
      exhausted = true;
      block_status =
          KeepaliveBlockStatus::kBlockedDueToTotalSizeOfUrlAndHeaders;
    } else if (recorder.GetTotalRequestSizePerTopLevelFrame(top_frame_id) +
                   keepalive_request_size >
               384 * 1024) {
      block_status =
          KeepaliveBlockStatus::kNotBlockedButUrlAndHeadersExceeds384kb;
    } else if (recorder.GetTotalRequestSizePerTopLevelFrame(top_frame_id) +
                   keepalive_request_size >
               256 * 1024) {
      block_status =
          KeepaliveBlockStatus::kNotBlockedButUrlAndHeadersExceeds256kb;
    } else {
      block_status = KeepaliveBlockStatus::kNotBlocked;
    }
  }

  if (exhausted) {
    URLLoaderCompletionStatus status;
    status.error_code = net::ERR_INSUFFICIENT_RESOURCES;
    status.exists_in_cache = false;
    status.completion_time = base::TimeTicks::Now();
    mojo::Remote<mojom::URLLoaderClient>(std::move(client))->OnComplete(status);
    return;
  }
  // ... 
}

可以看到,有多种情况会导致 exhausted = true,而一旦exhausted = true,就会报ERR_INSUFFICIENT_RESOURCES.

我们将加了LOG(ERROR)的编译版本发给客户 A,安装好并给快捷方式启动命令加上"--enable-logging",这样添加的 LOG(ERROR)就会记录到 chrome_debug.log 文件中.

接下来就静待客户复现问题了.

果然,几个小时后,客户 A 反馈说有一名 HR 遇到了 ERR_INSUFFICIENT_RESOURCES,我们立马远程,确认问题复现,并取回 chrome_debug.log.

打开 log 文件一看,立即定位到了以下代码:

  if (!context_->CanCreateLoader(params_->process_id)) {
    exhausted = true;
  }

因为 log 里所有报 ERR_INSUFFICIENT_RESOURCES 的都是此处.

Bug 复现

CanCreateLoader()代码如下:

// services/network/network_context.cc

bool NetworkContext::CanCreateLoader(uint32_t process_id) {
  auto it = loader_count_per_process_.find(process_id);
  uint32_t count = (it == loader_count_per_process_.end() ? 0 : it->second);
  return count < max_loaders_per_process_;
}

max_loaders_per_process_定义如下:

// services/network/network_context.h

  static constexpr uint32_t kMaxOutstandingRequestsPerProcess = 2700;
  uint32_t max_loaders_per_process_ = kMaxOutstandingRequestsPerProcess;

我们将 2700 调小一点,改成 50,以便让 bug 快速复现.再将CanCreateLoader()加上 LOG(ERROR),以便观察count值的变化.

然后编译 chromium,全新安装,加上"--enable-logging"打开,进入 Boss 直聘企业端后台,四处点一点.

然后发现,在和候选人"沟通"那里,切换候选人聊天界面时,count值快速增加,很快就超过了 50.

此时 log 里开始报 ERR_INSUFFICIENT_RESOURCES,但 Boss 直聘这个 tab 页操作还都正常.

然后新开一个 tab,访问 https://zhipin.com ,报错 ERR_INSUFFICIENT_RESOURCES.

到此,Bug 可以稳定复现了.

Bug 解决

// 此处省略 xxx 字

通过不停地加 LOG(ERROR)测试,最终发现这个问题和 xxxxxx 有关.

但这毕竟不是 Boss 直聘的后台,我们又改不了源码,也不能替他们修 Bug 了.

回复客户 A

我们将上述操作过程录制了视频,发给了客户 A.证明了 ERR_INSUFFICIENT_RESOURCES 和 OurATS 及插件没有一点关系.

在 Boss 直聘没修复这个 Bug 前,他们只能用一会 Boss 直聘就刷新一下页面,或者关闭这个 tab,再新开一个来凑合着用了.