线上问题:nginx日志打印时间问题
来源:互联网 发布:edu域名查询 编辑:程序博客网 时间:2024/05/22 00:38
有一个发送短信的功能,用户有7000人,要每人发送3条短信,结果用户描述,点击了一次,发送了2次短信,也就是没人发送了6条短信,据此排查问题。
查看kibana的nginx日志
从上面的日志分析,用户应该是点击了多次,因为发送时间没有规律可寻,应该不是程序触发的动作,也就是有可能前端没有控制好,点击发送短信的按钮。
但是有一个小插曲,到短信供应商的平台,查看短信发送情况,发现时间对不上,从nginx日志看,打印日志的时间,短信平台已经提前发送短信了。
走到这里,怀疑是nginx的log时间不对,查看nginx的配置的日志格式
log_format main '$remote_addr - $remote_user [$time_local] "$request" ' '$status $body_bytes_sent "$http_referer" ' '"$http_user_agent" "$http_x_forwarded_for" ' '"$http_host" "$upstream_response_time" "$request_time" "$request_body"'; access_log /home/logs/nginx/access.log main; error_log /home/logs/nginx/error.log;
time_local 就是我们在kibana上的时间
官方文档只是这样解释
$time_locallocal time in the Common Log Format
现在的疑问是:他是请求的时间还是nginx处理完成打印日志的时间。找到一个英文解释,我们验证一下
The $local_time variable contains the time when the log entry is written.when the HTTP request header is read, nginx does a lookup of the associated virtual server configuration. If the virtual server is found, the request goes through six phases:server rewrite phaselocation phaselocation rewrite phase (which can bring the request back to the previous phase)access control phasetry_files phaselog phaseSince the log phase is the last one, $local_time variable is much more colse to the end of the request than it's start.
查看我们自己tomcat请求发送短信的日志,在日志所在位置输入liunx命令:
cat -n catalina.2017-11-06.out | grep "发送短信操作开始" -B 2
可以看出:
20:57:27发送第一次请求,短信平台最早收到请求是20:58:00,后台把整个短信发完总处理时间为560.417秒,kibana中的时间为21:06:47,恰恰是20:57:27+560.417≈21:06:47
21:08:49发送第二次请求,短信平台最早收到请求是21:18:10,后台把整个短信发送处理时间为561.225秒,kibana中的时间为21:18:10,恰恰是21:57:27+561.225≈21:18:10
21:20:11发送第三次请求,短信平台没有收到请求,后台处理完成时间为40.743秒,kibana中的时间为21:20:51,恰恰是21:20:11+40.743≈21:20:51
经验证:time_local 是日志产生的时间
nginx日志中的其他两个时间的解释 :
1、request_time
官网描述:request processing time in seconds with a milliseconds resolution; time elapsed between the first bytes were read from the client and the log write after the last bytes were sent to the client 。
指的就是从接受用户请求的第一个字节到发送完响应数据的时间,即包括接收请求数据时间、程序响应时间、输出
响应数据时间。
2、upstream_response_time
官网描述:keeps times of responses obtained from upstream servers; times are kept in seconds with a milliseconds resolution. Several response times are separated by commas and colons like addresses in the $upstream_addr variable
是指从Nginx向后端(php-cgi)建立连接开始到接受完数据然后关闭连接为止的时间。
从上面的描述可以看出,
从上面的例子看,这个短信处理时间太长了,做的不合理,需要用优化。
- 线上问题:nginx日志打印时间问题
- nginx线上问题记录
- nginx日志打印相应时间
- Retrofit2 日志打印问题
- 线上问题
- brit打印日志的问题
- 日志打印两次(问题)
- pyspark命令行打印日志问题
- 线上Nginx跳转存在的接口返回异常问题
- MySQL 慢日志线上问题分析及功能优化
- JVM GC日志时间问题
- nginx 日志格式打印
- 排查线上问题
- 解决线上问题办法
- 线上问题排查
- 线上环境部署问题
- 线上问题处理
- 线上问题集锦
- 第十三节、给webpack增加babel支持
- vim配置utf-8
- SPEED 飞车扩容改造:敢于对过去说不
- 小程序之全局变量赋值
- 在<c:foreach 里面调用js代码
- 线上问题:nginx日志打印时间问题
- 虚拟机下安装ubuntu后root密码设置
- excel 查找/替换 回车键
- 学习《JS高级程序设计》(2)——原型
- Server-Sent Events和WebSocket服务器向浏览器推送信息
- openstack安装学习(环境)
- 利用tf.truncated_normal与tf.random_normal进行张量初始化的详解
- 对String在多线程中的一些简单认识
- 各主流浏览器之间的兼容性-JS篇