JAVA知识体系之问题处理篇（七）——上游传参错误导致Redis集群某个节点缓存命中率低（缓存击穿）

1、问题

  还是上文提到的核心应用，为了提升系统查询性能，我们在观察缓存命中率时，发现整体命中率都比较高，但是其中04集群的某个节点（99:36382）命中率一直比其他节点的命中率低。
  缓存命中率是我们非常关注的一个点，因为每一次未命中的请求都意味着对数据库的一次压力。

2、问题分析

  观察了下其他几个集群（该应用由于比较核心，配置了4个集群，由key进行hash到对应的集群上），发现并没有出现类似的情况。

  我们设置的缓存key一般由两部分组成，第一部分是前缀，用来区分缓存的业务类型，第二部分是编号，用来唯一确定一个对象value。在数据量足够大的情况下，使用这种方式基本可以保证key平均分布到每个master节点的槽位上。基于此，初步判断应该是某个没有带编号的key一直频繁查询，且在缓存中不存在导致的现象。
  使用redis monitor监控一段时间内该节点的get命令执行情况

1664517025.361671 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.364331 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.387473 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_****80024780***301"
1664517025.395242 [0 0.0.0.0] "GET" "XXX07****8036027571372"
1664517025.412444 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.413019 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_****80024780***301"
1664517025.433620 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_****80024780***301"
1664517025.453282 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.455593 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.456130 [0 0.0.0.0] "GET" "AUTHAPPLYINFO_FINDIDENTITYBYOPERATORNO_****8034200383480"
1664517025.458001 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.458461 [0 0.0.0.0] "GET" "AUTHAPPLYINFO_QUERYLASTAUTHFORGATEWAY_***30816002951160"
1664517025.460487 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.468908 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.469045 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.471383 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.473930 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.474447 [0 0.0.0.0] "GET" "XXX07***30564006195754"
1664517025.489570 [0 0.0.0.0] "GET" "XXX07****8032643731819"
1664517025.523515 [0 0.0.0.0] "GET" "XXX_OP_LOGIN_***31101941"
1664517025.531313 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.569774 [0 0.0.0.0] "GET" "XXX_AGREEMENT_INFO_****7037391502558_FINANCE"
1664517025.578509 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.581894 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.589476 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.601550 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.604348 [0 0.0.0.0] "GET" "XXX07****8032643731819"
1664517025.605715 [0 0.0.0.0] "GET" "XXX_AGREEMENT_INFO_****7033390393319_CASH"
1664517025.638155 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.663993 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.672103 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.681717 [0 0.0.0.0] "GET" "XXX****8037181058125"
1664517025.682689 [0 0.0.0.0] "GET" "XXX_AGREEMENT_INFO_****7037996619970_QUICK"
1664517025.695607 [0 0.0.0.0] "GET" "XXX_OP_LOGIN_***36300988"
1664517025.701713 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.718379 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.745512 [0 0.0.0.0] "GET" "XXX07****8032643731819"
1664517025.764437 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_****8035740934912"
1664517025.765464 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.786013 [0 0.0.0.0] "GET" "XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY"
1664517025.793828 [0 0.0.0.0] "GET" "XXX****8034200383480"
1664517025.820697 [0 0.0.0.0] "GET" "XXX_OP_LOGIN_***29218006"
1664517025.835956 [0 0.0.0.0] "GET" "XXX07****8034010117013"

  通过监控命令基本可以定位到出问题的KEY：XXX_CUSTOMER_INFO_OP_MIXPAY_WECHATPAY（因为其他KEY都是带编号的，理论上讲只要是带编号的，都会比较平均地分布到不同槽位）。
  查询了应用日志，发现有个上游系统送的operatorNo=MIXPAY_WECHATPAY（本来应该是个编号）。

3、问题解决

  同步上游系统，他们确认了对应的BUG并整改，问题修复。同时，内部进行了优化：入参增加了更严格的合法性校验，针对数据库查不到的场景，设置一个空值到缓存中（解决缓存击穿的基本玩法）。

4、问题思考

  居安思危：有时候生产环境看似平静如水，其实内部隐藏了不少坑，这些坑没有暴露出来我们只能把他归因为运气好。仔细想想，如果在活动期间这样的请求高了100倍或者1000倍，可能就把数据库压垮了。所以我们还是要多关注自己owner的应用，多去发现和修复隐患，保障生产安全稳定。