Soul网关源码分析-20期

集群模式下 HTTP 长轮询疑问

在上一章中我们分析了集群模式下各个同步方式是如何避免旧数据相互覆盖的. 但上次我还留有一个疑问点:

• HTTP 长轮询下, A、B先后发生变动, 此时B的缓存数据为最新, A中没有B的变动信息. 而网关此时通过 /config/fetch? 拉取数据, 先拉取B, 后拉取A, 是否会出现拉取到过时数据呢?

我们在 HttpSyncDataService 中做一个延迟, 如果是 A节点则延迟10秒请求 /config/fetch , 通过这样的方式来人为造成乱序的拉取情景

private void doFetchGroupConfig(final String server, final ConfigGroupEnum... groups) {
  log.info("线程: {}", Thread.currentThread().getName());
  if(server.indexOf("9095") != -1){
    try {
      log.info("当前节点为A 等待10秒再拉取数据");
      Thread.sleep(10000);
    } catch (InterruptedException e) {
    }
  }

  // ...
  String url = server + "/configs/fetch?" + StringUtils.removeEnd(params.toString(), "&");
  log.info("request configs: [{}]", url);
  String json = null;
  try {
    json = this.httpClient.getForObject(url, String.class);
  } catch (RestClientException e) {
  }
  // ...
}

在日志中看到如下信息:

2021-02-02 20:43:53.298  INFO 4876 --- [-long-polling-1] o.d.s.s.data.http.HttpSyncDataService    : http 路径: http://localhost:9095
2021-02-02 20:43:53.303  INFO 4876 --- [-long-polling-1] o.d.s.s.data.http.HttpSyncDataService    : 传输数据: [RULE]
2021-02-02 20:43:53.304  INFO 4876 --- [-long-polling-1] o.d.s.s.data.http.HttpSyncDataService    : 线程: soul-http-long-polling-1
2021-02-02 20:43:53.304  INFO 4876 --- [-long-polling-1] o.d.s.s.data.http.HttpSyncDataService    : 当前节点为A 等待10秒再拉取数据

2021-02-02 20:43:59.136  INFO 4876 --- [-long-polling-2] o.d.s.s.data.http.HttpSyncDataService    : http 路径: http://localhost:9096
2021-02-02 20:43:59.136  INFO 4876 --- [-long-polling-2] o.d.s.s.data.http.HttpSyncDataService    : 传输数据: [RULE]
2021-02-02 20:43:59.136  INFO 4876 --- [-long-polling-2] o.d.s.s.data.http.HttpSyncDataService    : 线程: soul-http-long-polling-2
2021-02-02 20:43:59.137  INFO 4876 --- [-long-polling-2] o.d.s.s.data.http.HttpSyncDataService    : request configs: [http://localhost:9096/configs/fetch?groupKeys=RULE]
2021-02-02 20:44:01.426  INFO 4876 --- [-long-polling-2] o.d.s.s.d.h.refresh.AbstractDataRefresh  : update RULE config: {...}

10秒钟后拉取A节点数据的日志也出来了

2021-02-02 20:44:03.305  INFO 4876 --- [-long-polling-1] o.d.s.s.data.http.HttpSyncDataService    : request configs: [http://localhost:9095/configs/fetch?groupKeys=RULE]
2021-02-02 20:48:46.082  INFO 4876 --- [-long-polling-1] o.d.s.s.d.h.refresh.AbstractDataRefresh  : Get the same config, the [RULE] config cache will not be updated, md5:b5cdba1cd805fc6eef088e513bc34f41
2021-02-02 20:48:46.087  INFO 4876 --- [-long-polling-1] o.d.s.s.data.http.HttpSyncDataService    : The config of the server[http://localhost:9095] has not been updated or is out of date. Wait for 30s to listen for changes again.

令人惊讶的是, 我准备好的陷阱并没有被 SOUL 网关触发, 它在这块进行了判断并取消了将 A 节点数据更新入缓存的动作.

但是随之而来的疑问又来了, 根据日志信息描述, 我的网关与 A 节点的数据 MD5 值是相同的. 这怎么可能呢, A 节点难道在我拉取数据的 10 秒钟内有其他动作?

带着疑问我们看下这行日志的所在位置 AbstractDataRefresh#updateCacheIfNeed.

protected boolean updateCacheIfNeed(final ConfigData<T> newVal, final ConfigGroupEnum groupEnum) {
  // first init cache
  if (GROUP_CACHE.putIfAbsent(groupEnum, newVal) == null) {
    return true;
  }
  ResultHolder holder = new ResultHolder(false);
  GROUP_CACHE.merge(groupEnum, newVal, (oldVal, value) -> {
    // must compare the last update time
    if (!StringUtils.equals(oldVal.getMd5(), newVal.getMd5()) && oldVal.getLastModifyTime() < newVal.getLastModifyTime()) {
      log.info("update {} config: {}", groupEnum, newVal);
      holder.result = true;
      return newVal;
    }
    // 日志打印在此处, 但是描述信息不符, 我们的场景不是配置的MD5不同, 而是A节点最后更新时间晚于网关缓存
    log.info("Get the same config, the [{}] config cache will not be updated, md5:{}", groupEnum, oldVal.getMd5());
    return oldVal;
  });
  return holder.result;
}

通过这里的断点以及代码分析, 我们明白了并不是 A 节点在 10 秒钟内还做了其他事, 而是由于 A 节点的数据最后更新时间晚于网关更新时间, 网关不进行更新.

那么这行日志的描述就不符合引发问题的现象了, 试着提个 PR 吧~