0607查日志定位问题有感

查日志

PS:由于是正式环境，关键信息已用xxxx代替。

查日志，也查了一段时间了，之前由于日志功能太垃圾了，无法定位，无法追踪，因此无法理解导致查日志要做什么，现在日志功能改进了好几次，也慢慢理解很多了。

今天齐又丢了两个业主反馈的问题过我，让我去找原因：

1.时间20180605，卡号170722130300xxxx，订单号20180531000004xxxx，订单状态12确认可疑，用户在对可疑订单进行圈存的时候，提示无法完成。
2.时间0607，卡号170922130300xxxx，车牌：桂kvxxxx，手机号码1362775xxxx，用户在绑卡时提示无效卡，无法绑定。

问题1

问题描述：
时间20180605，卡号170722130300xxxx，订单号20180531000004xxxx，订单状态12确认可疑，用户在对可疑订单进行圈存的时候，提示无法完成。

首先，不要直接就去查日志，先查数据库，根据订单号去我们数据库里查，发现确实是有这么一笔订单状态为12（可疑订单）的订单。查了数据库，也能确定用户反馈问题时报的手机号码，订单号，卡号等数据是否正确，如果不正确，查日志也查不到。

查日志的过程就略了，但其实不是那么简单，之前的日志功能超级垃圾，当各种用户的日志记录穿插在一起时，就无法追踪具体用户的操作记录了，现在日志功能改进后，就好很多了。由于用户反馈的是可疑订单在圈存的时候出现问题，那么对应的就是dubious方法和recursion方法了。因此我是通过正则表达式+关键字如卡号，useruuid进行查找，迅速定位到关键信息。

这里将涉及到的日志记录提取出来放到一起，去除了中间穿插了其他没用的日志信息：

[2018-06-05 15:18:40.298] -- [http-nio-8080-exec-6] -- [INFO] -- [OrderServiceImpl.java:472 >>>> Method = dubious] -- [Content = service dubious方法正常结束，可疑订单情况为：com.uroad.etc.dto.OrderDubiousOutput@7ed13959[tradState=4,tips=您有一笔订单未充值到卡上，请点击“确定”，系统将为您充值写卡！,tradeDate=20180601,tradTime=183135,orderNo=20180531000004xxxx,tradMoney=500000,cardNo=170722130300xxxx,orderType=1]]
[2018-06-05 15:18:50.763] -- [http-nio-8080-exec-17] -- [INFO] -- [StoreServiceImpl.java:228 >>>> Method = recursion] -- [Content = 调用【仪电9001卡操作】接口结束，response deceode data（头四位表示应答码）：0099800000000000]
[2018-06-05 15:18:50.764] -- [http-nio-8080-exec-17] -- [WARN] -- [BaseService.java:50 >>>> Method = verifyOk] -- [Content = ========待抛出异常============[(YD0099)系统未知错误]]
[2018-06-05 15:18:50.764] -- [http-nio-8080-exec-17] -- [ERROR] -- [StoreController.java:174 >>>> Method = recursion] -- [Content = 捕获BusinessException：com.uroad.etc.dto.OutputObject@6fcfa647[statusCode=YD0099,message=系统未知错误,data=<null>]]
[2018-06-05 15:18:50.764] -- [http-nio-8080-exec-17] -- [WARN] -- [StoreController.java:183 >>>> Method = recursion] -- [Content =         <<<用户uuid为f776ce19-5d66-11e8-b2ad-7cd30ad3xxxx，订单号20180531000004xxxx，号码1990635xxxx，在调用【/store/recursion】(空充卡操作)时，结果提示：YD0099错误，错误信息为：系统未知错误]

可以看出，确实是有一笔可疑订单，然后在圈存的时候出现了YD未知异常。由于我们是调用YD那边的接口，因此现在返回了YD错误信息，就要去问YD的对接人。

于是我去问刘维凯：

LLLLLLLLLLLLLLEE  16:49:32
有个日志问题，要你帮忙看看是什么原因。6月5号，卡号170722130300xxxx，订单号20180531000004xxxx，这个用户的订单状态在我们这边是12可疑订单，在你那边是什么状态？
他这笔订单在圈存的时候，在调用9001接口的时候，返回了(YD0099)系统未知错误。
刘维凯  16:53:19
这个你要查了干嘛 
有什么用 
LLLLLLLLLLLLLLEE  16:53:45
正式环境的啊。。。
业务反馈的问题
刘维凯  16:53:54
可疑了报客服 
不用来报我 
LLLLLLLLLLLLLLEE  16:54:25
噢噢 记住了！
刘维凯  16:56:03
这张卡预充值前 卡账户应该是负值 预充值后卡账户的余额就会小于圈存金额 这就是他可疑的原因 这种以后全报客服 
LLLLLLLLLLLLLLEE  16:56:06
可以确认下这个订单号在你们数据库里的订单状态吗？
刘维凯  16:56:10
12
LLLLLLLLLLLLLLEE  16:56:29
好的

凯哥是仪电那边的对接人，脾气有点暴躁，每次问他问题都好怕怕。他的意思就是，这笔订单确认是可疑的，就要交由客服人员去处理，而不要找他。

不过他还是给出了解答。我查日志，就是要找到用户出错的具体地方，找到在代码中出现异常的位置，获取异常信息，或许能自己找到原因，或者得问第三方对接人。

问题2

问题描述：
时间0607，卡号170922130300xxxx，车牌：桂kvxxxx，手机号码1362775xxxx，用户在绑卡时提示无效卡，无法绑定。

我去数据库绑卡表里查了一下，根据卡号，查不到记录。根据车牌号，手机号，uuseruuid号，都找不到。很奇怪。

其实并没什么奇怪的，可能是新用户吧，而且绑卡失败，因为没有绑卡表里没有任何记录。那就去数据库里查吧。

根据卡号去查，查不到任何信息，很奇怪！
根据手机号去查，查到useruuid，然后顺着useruuid去查，由于是下单接口，因此根据bind关键字+useruuid值，使用正则表达式进行匹配查询。

然后查到了相关的信息：

[2018-06-07 16:09:43.095] -- [http-nio-8080-exec-19] -- [INFO] -- [CardController.java:92 >>>> Method = newBind] -- [Content = 入参：{
  "plateNo" : "桂kvxxxx",
  "phone" : "1362775xxxx",
  "cardNo" : "170922130300xxxx",
  "useruuid" : "a98a2f9c-6a23-11e8-b2ad-7cd30ad3xxxx",
  "userid" : "34xxxx",
  "plateColor" : "01",
  "verifyType" : "1",
  "verificationCode" : "80xxxx"

[2018-06-07 16:09:49.432] -- [http-nio-8080-exec-19] -- [WARN] -- [BaseService.java:50 >>>> Method = verifyOk] -- [Content = ========待抛出异常============[(YD1030)卡片验证无效]]
[2018-06-07 16:09:49.433] -- [http-nio-8080-exec-19] -- [ERROR] -- [CardController.java:101 >>>> Method = newBind] -- [Content = 捕获BusinessException：com.uroad.etc.dto.OutputObject@1fc4860e[statusCode=YD1030,message=卡片验证无效,data=<null>]]
[2018-06-07 16:09:49.433] -- [http-nio-8080-exec-19] -- [WARN] -- [CardController.java:110 >>>> Method = newBind] -- [Content =         <<<用户uuid为a98a2f9c-6a23-11e8-b2ad-7cd30ad3xxxx，卡号170922130300xxxx，号码1362775xxxx，在调用【/card/bind】(云通卡绑定)时，结果提示：YD1030错误，错误信息为：卡片验证无效]

然后发现，用户在输入卡号的时候输入的不是他向客服反馈的卡号170922130300xxxx，而是日志里的170922130300xxxx。

这是什么鬼？？？

然后我跟齐说，齐就说应该是用户可能有多辆车，而错将这张卡对应那辆车。由于一卡一车，因此当卡号和车牌号对不上的时候，就会出现这个问题。应该是YD那边去调车管所的车卡绑定表。发现，卡和车牌对不上，于是就返回YD1030错误：卡片验证无效。

总结

因此，查日志，就是通过日志还原用户的操作过程，然后从日志里找到用户操作出错的原因。

日志能查的前提是，你日志功能做好了。否则，由于同一时间有几百几千甚至更多的人在使用app，因此各个用户的操作记录会穿插在一起，如果没有一个良好的日志系统，即没有很多的方法去区分用户，追踪用户行为，那么当排查日志的时候，就会心力交瘁，甚至无从下手。因此查日志之前，是先把日志功能做好。日志功能，我已经改进了好几次了！！！

但是有时查日志，还是会很茫然，有时会晕头转向。查日志，也需要把系统搞懂，把业务搞懂，这样头脑才能更加的清晰，才知道具体应该怎么做。我现在对系统的代码还不是很熟悉，所以有时看日志，还是看得很慢，甚至有时会不知道该怎么看。