排查NGINX的openfilecache导致发布后访问404的问题
# 1,问题
近来,有测试同学反馈测试环境的前端项目,在代码发布之后,再次访问会出现 404 的情况,希望我们能介入排查定位一下原因。
于是,我约好会议室,拉上前端同学一起,她来发代码,我们来访问验证,而后的确复现了如上问题:
- 在发布完成之后有一段时间会获取到上一次发布的入口文件的 hash。
我们进行了逐层的排除法验证,在排除了各层 NGINX 对 html 的缓存问题,排除了代码发布到主机与通过 nfs 挂载到 pod 的代码是否同时更新的问题,排除了浏览器缓存的问题,由于每次验证都需要前端重新发布,编译过程略长,因此不知不觉已经花了很长时间,虽然复现了现象,但仍旧没有什么头绪定位到根因。
# 2,定性
最后,请了部门老司机力哥出山,听了描述之后他也大为惊奇,不过老司机就是不一般,给他配套好环境之后,就开始了 pod 内那个 NGINX 的验证(他的说法,排除法应该先从代码最近的部位开始),最后给力的力哥经过一番排查终于定位到了问题,也让我们前两个小时的排查工作算是没白做。
这里先说结论,导致此次问题的原因是 pod 内的 NGINX 主配置文件开启了文件描述符缓存,又因为前端是通过 nfs 将代码挂载到 pod,并不需要重启 pod,从而代码发布之后会有一段时间,拿到的是缓存的文件。
原配置如下:
open_file_cache max=204800 inactive=60s;
open_file_cache_min_uses 1;
open_file_cache_valid 80s;
2
3
open_file_cache
max
:表示设置缓存文件的最大数目为 204800, 超过此数字后 Nginx 将按照 LRU 原则 (opens new window)丢弃冷数据。inactive
:与 open_file_cache_min_uses 1 表示如果在 60s 天内某文件被访问的次数低于 1 次,那就将它从缓存中删除。
open_file_cache_valid
:表示每 3 分钟检查一次缓存中的文件元信息是否是最新的,如果不是则更新之。
事实上在我们验证现象的过程中,正符合了 open_file_cache_valid
配置的 80s 的预期,代码发布之后,我们每秒访问一次,一开始访问的都是上个版本的文件,大约一分多钟之后,会更新到新文件。这个参数针对的是文件描述符的缓存,之前我们的思路已经停留在文件是否缓存中,于是看到请求的 response header 中带着 no-store 时就只觉得奇怪。
关于如上参数的讲解,CSDN 一篇文章做了极好的剖析与挖掘,接下来内容大多借鉴其内容,特此说明:Nginx open_file_cache 模块 文件描述符缓存 (opens new window)。
# 3,深挖
参数:
open_file_cache max=204800 inactive=60s;
open_file_cache_min_uses 1;
open_file_cache_valid 80s;
2
3
- 配置区域:http 区域,server 区域,location 区域。
# 1,open_file_cache
启用此指令将存储以下信息的缓存:
- 打开的文件描述符和相关元数据,如大小,修改时间等
- 文件和目录的存在与查找相关的任何错误,例如“权限被拒绝”,“文件未找到”等
- 缓存定义固定大小,并且在溢出期间,它移除最近最少使用(LRU)元素。
- 缓存在一段时间不活动之后逐出元素。 默认情况下禁用该指令。
启用 nginx 的 open_file_cache 指令可以对打开的文件句柄进行缓存,从而节约昂贵的 open() 系统调用。通过扩大这个缓存的容量可以提高线上的实际命中率。但是缓存容量并不是越大越好,比如当达到 20000 个元素的容量时,共享内存的锁就成了瓶颈。 (Nginx 的 open_file_cache 相关配置可以缓存静态文件的元信息,在这些静态文件被频繁访问时可以显着提升性能)
# 2,open_file_cache_valid
http{
open_file_cache_valid 30s;
}
2
3
NGINX 的 openfile_cache 保存信息的快照。 由于信息在源处更改,快照可能在一段时间后无效。 open_file cache_valid 指令定义时间段(以秒为单位),之后将重新验证 open_file_cache 中的元素。默认情况下,60 秒后重新检查元素。经过 60s 之后再去看缓存的内容是否有效,如果发生了更新,那么需要更新。
这样做的原因是因为虽然缓存了文件,但是有其他的进程,比如用户或者其他的服务没有通过 nginx 在修改文件,这会导致 nginx 缓存的 fd 句柄指向的文件不是最新的文件,特别是配置的时间特别大,缓存文件句柄数特别多的时候,很有可能导致客户拿到的是过期的文件,所以要设置这个时间要保证在这个时间以后,如果磁盘上的文件发生变化,那么我们还可以去获取新的文件。
- 如果你的静态文件内容变化频繁并且对时效性要求较高,一般应该把 open_file_cache_valid 设置的小一些,以便及时检测和更新。
- 如果变化相当不频繁的话,那就可以设置大一点,在变化后用 reload nginx 的方式来强制更新缓存。
- 对静态文件访问的 error 和 access log 不关心的话,可以关闭已提升效率。
# 3,open_file_cache_min_uses
http{
open_file_cache_min_uses 4;
}
2
3
此指令可用于配置最小访问次数以将元素标记为活动使用。 默认情况下,最小访问次数设置为 1 次或更多次(至少要访问多少次才能留在缓存当中)。
# 4,open_file_cache_errors
http{
open_file_cache_errors on;
}
2
3
NGINX 可以缓存在文件访问期间发生的错误。但是这需要通过设置 open_file_cache_errors 指令来启用。 如果启用错误缓存,则在访问资源(不查找资源)时,NGINX 会报告相同的错误。默认情况下,错误缓存设置为关闭。
综合而言,一般建议配置参考为如下参数:
open_file_cache max=10000 inactive=30s;
open_file_cache_valid 60s;
open_file_cache_min_uses 2;
open_file_cache_errors on;
2
3
4
当然,如果你的应用场景是那种需要所见即所得的场景,则不建议配置如上配置,以免遇到和我上边一样的遭遇。
# 5,为什么缓存文件描述符
这个问题的关键是 sendfile(2)
Nginx 在 serve 静态文件的时候用的是 sendfile(2), 当然前提是你配置了 sendfile on
。
sendfile(2) 直接在
kernel space
内传输数据,对比使用read(2)/write(2)
省去了两次kernel space
与user space
之间的数据拷贝。而同时这些被频繁读取的静态文件的内容会被 OS 缓存到 kernel space。在这样的机制下,我们缓存中有文件的 fd 和 size,直接调用 sendfile(2) 就可以了。
如果要 Nginx 连内容一起缓存,那就需要每次文件变化都要用 read(2) 将数据从 kernel space 复制到 user space,然后放在 user space,每次应答请求的时候再从 user space 复制到 kernel space 然后写入 socket。比起前面的方式,这样的方式毫无优点。
# 6,看见它
接着我们通过实际测试来看见 NGINX 在处理请求时,开启与关闭如上参数的效果对比,事实上,上边力哥在排查此问题的时候,也是通过 strace 追查到了端倪,因此这里我们一起做下实验,一次一次,强化对 strace 的认知。
首先我们来看关闭 open_file_cache
的访问效果,添加如下配置到 NGINX:
server {
listen 80;
server_name www.test.com;
charset utf-8;
root html;
location / {
# open_file_cache max=10 inactive=60s;
# open_file_cache_min_uses 1;
# open_file_cache_valid 60s;
}
}
2
3
4
5
6
7
8
9
10
11
为了便于验证效果,这里建议此测试 NGINX 只保留这一个 server 配置,以便于抓到我们的请求,另外把 NGINX 的 work 数调成 1,同样便于我们抓到 work 进程的处理详情。
配置完毕之后,我们可以拿到进程 ID,然后进行抓包:
$ ps aux |grep nginx | egrep -v "grep|master"
root 29381 0.0 0.0 71580 6396 ? S 16:40 0:00 nginx: worker process
$ strace -p 29381 -Ttf
strace: Process 29381 attached
16:42:00 epoll_wait(10,
2
3
4
5
6
这个时候没人去访问可以看到挂在 epoll_wait 上面。
然后再开个窗口请求本机:
$ curl localhost
$ $strace -p 29381 -Ttf
strace: Process 29381 attached
16:41:26 epoll_wait(10, [{EPOLLIN, {u32=59129872, u64=140436899774480}}], 512, -1) = 1 <8.995934>
16:41:35 accept4(6, {sa_family=AF_INET, sin_port=htons(45869), sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_CLOEXEC|SOCK_NONBLOCK) = 4 <0.000028>
16:41:35 epoll_ctl(10, EPOLL_CTL_ADD, 4, {EPOLLIN|EPOLLRDHUP|EPOLLET, {u32=59130352, u64=140436899774960}}) = 0 <0.000021>
16:41:35 epoll_wait(10, [{EPOLLIN, {u32=59130352, u64=140436899774960}}], 512, 60000) = 1 <0.000020>
16:41:35 recvfrom(4, "GET / HTTP/1.1\r\nUser-Agent: curl"..., 1024, 0, NULL, NULL) = 73 <0.000018>
16:41:35 stat("/usr/local/openresty/nginx/html/index.html", {st_mode=S_IFREG|0644, st_size=649, ...}) = 0 <0.000022>
16:41:35 open("/usr/local/openresty/nginx/html/index.html", O_RDONLY|O_NONBLOCK) = 5 <0.000020>
16:41:35 fstat(5, {st_mode=S_IFREG|0644, st_size=649, ...}) = 0 <0.000016>
16:41:35 writev(4, [{"HTTP/1.1 200 OK\r\nServer: openres"..., 250}], 1) = 250 <0.000040>
16:41:35 sendfile(4, 5, [0] => [649], 649) = 649 <0.000035>
16:41:35 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000030>
16:41:35 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000026>
16:41:35 lstat("/usr/local/openresty", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000055>
16:41:35 lstat("/usr/local/openresty/nginx", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000033>
16:41:35 lstat("/usr/local/openresty/nginx/html", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000030>
16:41:35 write(7, "{\"remote_addr\": \"127.0.0.1\",\"@ti"..., 537) = 537 <0.000047>
16:41:35 close(5) = 0 <0.000031>
16:41:35 setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0 <0.000046>
16:41:35 epoll_wait(10, [{EPOLLIN|EPOLLRDHUP, {u32=59130352, u64=140436899774960}}], 512, 300000) = 1 <0.000027>
16:41:35 recvfrom(4, "", 1024, 0, NULL, NULL) = 0 <0.000028>
16:41:35 close(4) = 0 <0.000062>
16:41:35 epoll_wait(10,
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
可以看到
epoll_wait
返回了accept
建立了一个新的TCP
连接,之后调用recvfrom
获取到请求的内容,然后使用stat
看看访问的首页内容是否存在,可以看到是存在的并且大小是 st_size=649 字节,而且访问的权限是 st_mode=S_IFREG|0644 0644。之后打开文件获取到句柄open
("/usr/local/openresty/nginx/html/index.html", O_RDONLY|O_NONBLOCK) = 5,现在拿着这个句柄将数据返回,数据的返回时通过 sendfile(4, 5, [0] => [649], 649) = 649。
这里需要注意
sennfile
是优化的一个关键点,因为 sendfile 是一个0拷贝
技术,即不需要从磁盘读到用户态,再从用户态发到内核态,再经过网卡发出去,而是有了 sendfile 调用直接告诉文件,以及文件偏移量,直接就在内核态之中把磁盘上的内容发到网卡上,所以说这个性能是很高的。 但是引入了 open("/usr/local/openresty/nginx/html/index.html", O_RDONLY|O_NONBLOCK) = 5 和 close(5) 就没有必要了,因为做sendfile就没有必要去做open和close的
,因为 nginx 性能作为用户态没必要去打开的(这是我们优化的关键点)。 通过 senfile 将数据发给了客户端,又做了一次 epoll_wait(10, [{EPOLLIN|EPOLLRDHUP, {u32=13621248, u64=13621248}}], 512, 65000) = 1,epoll_wait(10,,在这里等着以后的请求。
然后我们来看开启 open_file_cache
的访问效果,添加如下配置到 NGINX:
server {
listen 80;
server_name www.test.com;
charset utf-8;
root html;
location / {
open_file_cache max=10 inactive=60s;
open_file_cache_min_uses 1;
open_file_cache_valid 60s;
}
}
2
3
4
5
6
7
8
9
10
11
重新加载 NGINX,然后访问并抓包:
$ strace -p 30078 -Ttf
strace: Process 30078 attached
16:53:36 epoll_wait(10, [{EPOLLIN, {u32=59129872, u64=140436899774480}}], 512, -1) = 1 <3.077562>
16:53:39 accept4(6, {sa_family=AF_INET, sin_port=htons(45903), sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_CLOEXEC|SOCK_NONBLOCK) = 3 <0.000019>
16:53:39 epoll_ctl(10, EPOLL_CTL_ADD, 3, {EPOLLIN|EPOLLRDHUP|EPOLLET, {u32=59130352, u64=140436899774960}}) = 0 <0.000039>
16:53:39 epoll_wait(10, [{EPOLLIN, {u32=59130352, u64=140436899774960}}], 512, 60000) = 1 <0.000029>
16:53:39 recvfrom(3, "GET / HTTP/1.1\r\nUser-Agent: curl"..., 1024, 0, NULL, NULL) = 73 <0.000028>
16:53:39 open("/usr/local/openresty/nginx/html/index.html", O_RDONLY|O_NONBLOCK) = 8 <0.000033>
16:53:39 fstat(8, {st_mode=S_IFREG|0644, st_size=649, ...}) = 0 <0.000026>
16:53:39 writev(3, [{"HTTP/1.1 200 OK\r\nServer: openres"..., 250}], 1) = 250 <0.000232>
16:53:39 sendfile(3, 8, [0] => [649], 649) = 649 <0.000045>
16:53:39 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000046>
16:53:39 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000029>
16:53:39 lstat("/usr/local/openresty", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000027>
16:53:39 lstat("/usr/local/openresty/nginx", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000029>
16:53:39 lstat("/usr/local/openresty/nginx/html", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000029>
16:53:39 write(5, "{\"remote_addr\": \"127.0.0.1\",\"@ti"..., 537) = 537 <0.000046>
16:53:39 setsockopt(3, SOL_TCP, TCP_NODELAY, [1], 4) = 0 <0.000031>
16:53:39 epoll_wait(10, [{EPOLLIN|EPOLLRDHUP, {u32=59130352, u64=140436899774960}}], 512, 300000) = 1 <0.000029>
16:53:39 recvfrom(3, "", 1024, 0, NULL, NULL) = 0 <0.000028>
16:53:39 close(3) = 0 <0.000046>
16:53:39 epoll_wait(10,
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
第一次没有做缓存,可以看到使用了 open("/usr/local/openresty/nginx/html/index.html", O_RDONLY|O_NONBLOCK)
以及 close(3)
。
接着再访问一次:
16:54:24 accept4(6, {sa_family=AF_INET, sin_port=htons(45907), sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_CLOEXEC|SOCK_NONBLOCK) = 3 <0.000041>
16:54:24 epoll_ctl(10, EPOLL_CTL_ADD, 3, {EPOLLIN|EPOLLRDHUP|EPOLLET, {u32=59130353, u64=140436899774961}}) = 0 <0.000155>
16:54:24 epoll_wait(10, [{EPOLLIN, {u32=59130353, u64=140436899774961}}], 512, 60000) = 1 <0.000076>
16:54:24 recvfrom(3, "GET / HTTP/1.1\r\nUser-Agent: curl"..., 1024, 0, NULL, NULL) = 73 <0.000122>
16:54:24 writev(3, [{"HTTP/1.1 200 OK\r\nServer: openres"..., 250}], 1) = 250 <0.000145>
16:54:24 sendfile(3, 8, [0] => [649], 649) = 649 <0.000043>
16:54:24 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000018>
16:54:24 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000015>
16:54:24 lstat("/usr/local/openresty", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000016>
16:54:24 lstat("/usr/local/openresty/nginx", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000017>
16:54:24 lstat("/usr/local/openresty/nginx/html", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000017>
16:54:24 write(5, "{\"remote_addr\": \"127.0.0.1\",\"@ti"..., 537) = 537 <0.000023>
16:54:24 setsockopt(3, SOL_TCP, TCP_NODELAY, [1], 4) = 0 <0.000025>
16:54:24 epoll_wait(10, [{EPOLLIN|EPOLLRDHUP, {u32=59130353, u64=140436899774961}}], 512, 300000) = 1 <0.000034>
16:54:24 recvfrom(3, "", 1024, 0, NULL, NULL) = 0 <0.000047>
16:54:24 close(3) = 0 <0.000058>
16:54:24 epoll_wait(10,
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
可以看到第二次访问接收到请求直接调用了
sendfile(3, 8, [0] => [649], 649) = 649
,没有见到上面的open("/usr/local/openresty/nginx/html/index.html", O_RDONLY|O_NONBLOCK) = 8
以及fstat(8, {st_mode=S_IFREG|0644, st_size=649
。
此处可以明显看到 NGINX 在处理请求时,开启open_file_cache
与否对所占用的系统开销是有不小影响的。当 nginx 访问量非常大的时候,通过此参数优化是很有帮助的。而且 open_file_cache 不仅仅用于返回的静态文件,它对所有的打开文件类型操作都是有效的,不管是日志文件还是缓存文件等等。
所以要确认我们的使用环境如果资源文件经常被 nginx 以外的进程经常访问修改发生变化,那么需要正确设置超时时间。(当我们的文件频繁的被 nginx 以外的进程修改时,那么需要保证其超时时间是合理的,被业务场景可以接收的。
那么像我们上边测试环境的这种场景,想要即时更新,而发布过程中 NGINX 又没有更新的情况下,就应该关闭掉这些参数。