8

背景

业务架构:

clipboard.png

部署细节:
  两容器均部署在同一机器上,通过 docker-compose 编排,并且通过link方式链接。

故障描述

在有次更新代码时,发现前端能够打开,但是所有接口请求全是502(Bad GateWay)

clipboard.png

故障排查

查看前端容器compose_ui_1的日志,刷了一大波502(Bad GateWay)

clipboard.png

UI没问题的话,第一反映就是 compose_api_1 跪了,所以直接去容器看看日志
clipboard.png

容器日志看起来很正常,没有崩溃,而且这个日志就好像从来没收到请求那样,但是很明显我前端肯定有访问的,感觉很奇怪。将接口取出来单独访问试试看:
clipboard.png

接口单独访问结果还是很残暴的502(Bad GateWay),感觉还是不太可信,是不是端口或者主机什么访问错误了?
本机开启 wireshark 抓包确认下请求的主机和端口:
clipboard.png

这样就很确保前端compose_ui_1访问的主机和端口是正确的,而且确切结果是502(Bad GateWay),这样只能从compose_api_1下手排查了。

之前也是遇到相似的问题,因为compose_api_1是通过uwsgi部署的python flask,那会总是用法觉得有点问题,改过uwsgi配置之后消停了一会。现在又卷土重来了。

先判断下compose_api_1是不是真的跪了。。。虽然对这个没抱什么希望。。。

直接访问 后端api 接口
clipboard.png

额。。。尴尬。。。仿佛冤枉错好人了。这不对吧,抓包看看再次确认下先:
clipboard.png

仿佛真的是。。。再 see see 容器日志:
clipboard.png

额。。。好吧。。。我错了,compose_api_1没跪。

于是问题来了。。。后端接口没问题,前端访问出错了,见鬼了?

有种预感是容器的特性导致的问题。但愿不要。。

先进去compose_ui_1容器抓包分析下,看看整个请求链有没有问题:
clipboard.png

似乎发现了点猫腻,Flags[R.]是代表 tcp链接 被 reset 重置 了,但是为什么平白无故重置呢?

看到 172.17.0.5.8080 返回的, 先 telnet 问问先:
clipboard.png

What???这就很迷了,首先这个 172.17.0.5.8080 哪来的呢?其次就是为毛端口不通?

突然想到一个很重要的问题:

容器之间是怎么知道它要把请求发给谁呢 ?

在前面已经交代过,这两个容器是通过 link 的方式链接的,像下面这样:

clipboard.png

谷歌搜了下 link 工作原理:

link机制通过环境变量的方式提供了这些信息,除此之外像db的密码这些信息也会通过环境变量提供,docker将source container中定义的环境变量全部导入到received container中,在received container中可以通过环境变量来获取连接信息。

使用了link机制后,可以通过指定的名字来和目标容器通信,这其实是通过给/etc/hosts中加入名称和IP的解析关系来实现的

所以就是说在 compose_ui_1 的 根据指定的名字并在 /etc/hosts 翻译出具体的ip然后进行通信咯?
看看容器的名字是啥?

clipboard.png

compose_ui_1/etc/hosts

root@e23430ed1ed7:/# cat /etc/hosts
127.0.0.1    localhost
::1    localhost ip6-localhost ip6-loopback
fe00::0    ip6-localnet
ff00::0    ip6-mcastprefix
ff02::1    ip6-allnodes
ff02::2    ip6-allrouters
172.17.0.4    detectapi fc1537d83fdf compose_api_1
172.17.0.3    authapi ff83f8e3adf2 compose_authapi_1
172.17.0.3    authapi_1 ff83f8e3adf2 compose_authapi_1
172.17.0.3    compose_authapi_1 ff83f8e3adf2
172.17.0.4    api_1 fc1537d83fdf compose_api_1
172.17.0.4    compose_api_1 fc1537d83fdf
172.17.0.6    e23430ed1ed7

如果真是按照资料所说,那 172.17.0.4:8080 才是 compose_api_1 的地址隐射才对吧?,试下先
clipboard.png
虽然返回了 auth product is None,但其实这是有效的请求。

再看看 compose_api_1 容器的日志:
clipboard.png

所以基本没跑了, 为什么前端访问直接就是 502, 原因就是 ui容器向错误的地址发送请求了

那么为什么会这样呢?平白无故抽风了?

刚才根据 host 的记录实验了,按照它的映地址发起接口请求,是没有问题的:

查看下 compose_ui_1nginx 日志
clipboard.png

尴尬。。。 nginx 日志居然直接连接到标准输出和标准错误。。。
那为了简单点,还是直接用 docker logs 查看吧
clipboard.png

看来 nginx 的转发已经是错误的,为什么会转发到 172.17.0.5, 看看 nginx 关于转发的配置:
clipboard.png

这个 detectapi 和 上面贴出的 hosts 表能找到正确的地址 172.17.0.4 呀?搞不明白为什么会转发到 172.17.0.5

难道是系统的域名解析错误了?
clipboard.png

尼玛这真是太神奇了。

男人的直觉告诉我 nginx 有猫腻!

重启下容器的 nginx,然而容器也被重启了。。。
clipboard.png

再访问页面,居然可以了。。。
clipboard.png

再看看容器的nginx日志,已经转发成功了
clipboard.png

这样子的话,其实应该能定位到,问题是出在了 nginx 上面?

故障定位

只是为什么 nginx 会有这样的错误呢?不太应该呀。。 感觉应该是 nginx 内部域名解析缓存问题。

然后查了下资料,呵呵,还真有。https://www.zhihu.com/questio...

clipboard.png

这就非常尴尬了。对这个问题抱有点怀疑,咨询了资深大佬,然后大佬的回复就是:

如果 proxy_pass 后面跟的域名的话,在 nginx 启动的时候就会初始化好,以后就只会复用这个值;参考:ngx_http_upstream_init_round_robin 函数
如果 proxy_pass 后面跟的是upstream,配置才会走解析和缓存的逻辑;

改善措施

  1. 不直接 proxy_pass 真实域名,而是转发到 upstream 配置;
  2. 也可参考刚才的知乎链接处理方案:https://www.zhihu.com/questio...

延展问题

  1. 为什么 compose_ui_1 指定的 compose_api_1 会出错?
  2. proxy_pass 如果后面跟真实域名,是真的直接复用还是有时间缓存?

本来想用 gdb 调试下这个问题,然而花了一天时间,毛都没有。不过也有点小收获,那就是如何配置nginx来支持gdb

1.修改编译配置文件:auto/cc/conf

ngx_compile_opt="-c"  改成 ngx_compile_opt="-c -g"

2../configure 时,增加编译参数:--with-cc-opt='-O0', 避免编译器优化;
例如:./configure --prefix=/usr/local/nginx --with-cc-opt='-O0' ....
如果不这样的话,编译器会优化代码,导致调试过程中,循环中的一些变量值无法打印,会报下面的错误:

value optimized out

下面可以看下调试的效果:
nginx worker process 处理入口:ngx_http_static_handler

clipboard.png
欢迎各位大神指点交流, QQ讨论群: 258498217
转载请注明来源: https://segmentfault.com/a/11...


Lin_R
5.2k 声望333 粉丝

准则一:简单即美。