今天是在博客园开园的第一天
一时间其实并不能想起来到底该写什么文章,其实想写的东西挺多
今天就以logid这个主题开始吧,网上写这个的文章似乎不多,但是的确是在实际生产中相当重要的一个能力,也是容易被大多数新手程序员所忽视的。
logid:在我的定义里,logid是一个能够代表一条请求唯一性的字段。完整请求包含请求到达、请求转发、服务处理、数据存取等多个阶段,logid在其中充当的就是一个定位标识,当然这个字段叫法可能不能可以是traceID或者其他XXID等等
以典型的php服务为例,整条请求轨迹可能包含下面的几个组成部分:
client => 外层网关(四层负载均衡) => nginx集群(七层负载均衡) => 你自己服务的nginx => 业务日志 => rpc日志 => mysqlproxy => mysql
=> redisproxy => redis
=> 其他基础服务(图片服务\评论服务等等)
上面展示的是一个比较完善的请求转发路径,而这样的长路径上,任何一个位置都可能产生问题。大部分情况下,每个阶段也都会打日志
如何把这些日志串联起来、让问题可追溯、请求可定位,这便是logid做的事情。
典型的使用场景例如:
案例一:业务可用性出现问题,如何排查问题出在哪里?
假设你自己的服务机器nginx出现了大量的499报错,499错误源于客户端主动断开连接。
那么问题可能处在哪里?
- 客户端的超时时间设置有问题,太短了(这个原因引起的499错误,只存在于上新服务。如果服务存在很久了,这个原因基本可以忽略)
- 客户端和你之前的网络故障,这也是一个常见的引起因素。(这个问题的定位可以把nginx_proc_time和upstream_time都打出来即可辨别)
- 极大的可能问题出在你的服务请求别人或者自己的机器负载过高导致的
今天主要讨论第三种,如何定位?
关键是看这条请求从nginx => pfm => php执行 => rpc请求这些过程哪些步骤出现了问题
没有logid的时候你怎么做?
nginx找到问题日志,根据get参数或者post参数去业务日志找,请求少的还好,如果大量重复请求呢?你是没办法精确定位到一个请求的
并且大部分rpc的日志不会打get参数,我们的rpc日志每秒百条,所以需要有一个线索,穿起来
logid就是扮演这个角色
nginx把请求上游的logid通过fastcgi带给php,php通过$SERVER中取到,然后rpc框架和php代码约定好从哪里取logid
done!下次再来问题,直接一步定位,不需要肉身来定位了
案例二: sql问题反查业务日志
假设某天DBA找到你说Proxy日志发现了大量的sql存在注入风险,并且抛给你一堆sql、来源IP和时间
一般如何处理?找到来源ip机器、找到对应时间的日志、翻译sql中的关键字到你的日志关键字(人肉),这个步骤如果没法对应起来,可能很困难
但是如果你们约定好了sql发出去的时候带上logid字段,这个情况是不是迎刃而解?你只需要grep相应的logid便可以找到对应的,效率也会高很多
如何在发sql请求带上logid?可以使用类似下面的sql语句,proxy完成sql日志打印
/*logid=xxx*/select count(1) from tableA
当然还有很多案例
logid存在的核心价值是让每一个请求都可以被唯一定位!
具体logid的协议如何定制需要具体问题具体分析,但是意识上在遇到类似问题的时候应该想到,你的服务需要在日志中打印线索ID:logid来让你的每一个请求可以被定位
当然前提是log打的充分、也要恰当