【问题定位】Etcd连不上背后的原因竟是端口号被占满了？

FamousMai
238 阅读3分钟

故事背景

最近在解耦一个微服务，这个微服务包含了两大块的功能，数据库运维以及项目构建部署，本身服务名称叫做dbm-service，所以项目构建部署相关的功能，不应该放在这个服务里，要解耦出来

开搞

  1. 复制整个 dbm-service 仓库，新建一个 project-service
  2. project-service 删掉 dbm 相关功能代码
  3. dbm-service 删掉 project 相关功能代码
  4. 重启 dbm-service
  5. 新开启 project-service
  6. 完事

要是有这么简单就好了，想得美

测试环境发现问题

在愉快地进行开发一段时间后，在某一天突然发现

1. 主机 CPU 飙高

image.png

2. 在Grafana日志平台上，发现报了大量etcd连不上的信息，一直在重连

{
    "level": "warn",
    "ts": "2023-11-20T17:52:16.143+0800",
    "logger": "etcd-client",
    "caller": "v3@v3.5.1/retry_interceptor.go:62",
    "msg": "retrying of unary invoker failed",
    "target": "etcd-[endpoints://0xc05e2fa700/xx.xx.x.xx:2376]()",
    "attempt": 0,
    "error": "rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing dial tcp xx.xx.x.xx:2376: connect: cannot assign requested address\""
}

自从在测试环境起了 project-service 之后，

3. 之前也出现过类似的问题，定位如下

  1. 本次更新没改动代码，只改了配置，已查看上次版本更新确认不是代码变动导致
  2. 怀疑是加载配置有问题，回滚了配置，重启启动服务也失败
  3. 用了线上配置，本地运行服务，正常无误
  4. 怀疑是jekins打包程序有问题，本地打包程序放到线上运行，依旧失败
  5. 补充打印日志信息，报错 listen tcp :0: bind: address already in use
  6. 确认问题，获取不到空闲端口
  7. 查看当前tcp连接，发现 ESTABLISHED 占用了2万多个，大部分是连接etcd
  8. kill掉webhooks服务，然后就释放了这些tcp连接，重启服务就正常了
  9. 初步分析是webhooks服务，没有释放tcp连接，一直占用
  10. 但是之前服务已经运行了很久
  11. 前面提到etcd配置，发现最近确实更新了etcd配置，但都重启了服务

4. 现在定位的原因

  1. 今天发现测试环境机器的tcp端口号又被占满了
  2. 查看对应服务占用端口数变化情况：netstat -pnt | grep {对应服务进程id} | wc -l
  3. 发现project服务占用端口数保持不变，dbm和resource服务占用端口数一直稳步上升
  4. 怀疑最近新上project服务导致的
  5. 查看对应机器的tcp监控数据，端口号数量开始上升的时间，恰好跟project服务上测试环境时间一致
  6. 确定跟project服务有关，一顿测试后
  7. 发现【project服务少了心跳的rpc接口】，导致project服务虽然注册到etcd上，但是【其他服务却ping不通】
  8. 其他服务ping不通，就会进行重试，但【重试时只关闭了rpc的连接，没有close掉etcd连接】
  9. 导致etcd连接一直没有释放掉，而又不断重试，最终把机器的端口号占满

反思

  1. 对于一些错误，即使不做处理，也应该直接打印到日志里（如，此次调用心跳rpc接口，我定位了很久补上日志，才发现问题出在这里）
  2. 创建的一些tcp连接，要关注是否有重复创建情况或者有没有close掉（如，此次问题创建的etcd连接异常情况下就重复创建了）
avatar
文章
阅读
粉丝