破涕为笑，一个node中间层bug我让同事的名字出现在全球用户的页面上

前言

近期遇到了一个线上故障，排查花了很多时间精力，在bug复现过程中，我还不小心让同事的名字出现在了全球用户的页面上，从“一把辛酸泪”到“破涕为笑”，感觉特别有意思。本文中的代码、描述都过滤了敏感信息，以简单demo的形式复现该故障。

如下图，不管用户搜索啥词，每个用户页面回显的都是sivan

业务功能描述

站点的搜索功能，搜索功能会根据业务场景继续细分为a搜索，b搜索...，每种搜索在node中间层走的可能是不同的链路。

如下图展示，a搜索回显了default

b搜索回显了sang和for

故障描述

1. 
   
2. 偶现，但是触发频率很高
   
3. 现象为在x国家站点上，不管用户搜索什么内容，页面回显的大概率是一串固定的字符串
   
4. 只有在x国家站点会出现该故障，其他国家站点没有出现
   
5. 测试环境无法复现，只有线上环境会出现该故障
   

排查

炒面代码分析

从线上的故障现象来看，像是搜索词被替换掉了，分析看客户端页面下发的参数是没有任何问题的，找搜索服务的后端协助，后端说他们接收到的搜索词就已经是有问题的搜索词了。

初步猜测是被类似xssFilter之类的转换函数替换掉了原来的搜索词，或者node中间层有某一条链路的代码把搜索词改掉了。于是把node中间层的搜索链路的相关代码都研究了好几遍，通过关键字搜项目全局，把每个可疑的地方都看了，感觉代码逻辑写的都没毛病（node中间层的代码链路写得跟炒面一样，看得头都大了）。

没办法，代码分析不出来问题所在，测试环境又无法复现，只能在代码分析的基础上，把每个有可能改到搜索词的可疑地方打上日志，在搜索链路的一些比较关键的执行地方也打上日志，重新发版，来辅助排查。

// 线上打日志的时候需要注意加条件限制，不然每个用户请求都打日志，一下子就打爆了
if (req.query.sdebug === 's') {

  logger.warn({ /** data */ })

}

抓住日志这根救命稻草

之前也有猜测，可能是网关啊、waf啊把请求拦截下来更改了搜索词，所以我们在请求入口那里也打了日志。从日志上来看，从中间层入口进来时，此刻的搜索词还是正常的，说明不是网关、waf搞的鬼。第一次的日志帮助我们缩小了排查范围，但是还不能分析出来，还需要再补充一些日志，意味着还要再发版，没办法，就是这么麻烦。

考验你js能力的时候到了

日志只是一种辅助手段，帮你记录异常数据，缩小排查范围。是否能从一堆代码中找出那一行有问题的代码就要看你自己了，我把有问题的代码写成一个demo了，展示在下面，你能分析出来问题所在吗？

const express = require('express')
const app = express()

const aConfig = Object.freeze({
info: { word: 'default' },

  getWord ({ word }) {
return word

  },

})
const bConfig = Object.freeze({
info: {},

  getWord ({ req, word }) {
// 日志记录到这里word是'sivan'，正常word应该是undefined，取的是req.params[0]才对
return word || req.params[0]

  },

})

const setRequestData = ({ info: { word }, getWord }) => {
return (req, res, next) => {

    word = word || req.query.word

    res.end(getWord({ req, word })) // 回显搜索词

  }

}

const getHandler = (config) => {
return setRequestData(config)

}
const aSearch = getHandler(aConfig)
const bSearch = getHandler(bConfig)


app.get('/a-search', aSearch)

app.get(/^\/b-search\/([^\/]+)\/?$/, bSearch)


app.listen(2333, () => {
console.log('run')

})

开始揭开谜底

const setRequestData = ({ info: { word }, getWord }) => {
return (req, res, next) => {

    word = word || req.query.word // 罪魁祸首

    res.end(getWord({ req, word }))

  }

}

在a搜索链路中，word是有值的，为'default'。
在b搜索链路中，word和req.query.word都应该是undefined，所以b搜索链路传给getWord的word应该是undefined才对。

观察setRequestData这个函数的实现，它对config解构出了word变量，然后返回了一个中间件函数，word变量的作用域是在setRequestData的函数作用域里的，setRequestData函数只会执行一次，而中间件函数在每一次请求中都会执行。

中间件函数使用了word变量，这就创建了一个闭包，闭包使得word变量可以长期存储和被访问。

复现步骤如下：

1. 
   
2. 我们第一次输入http://localhost:2333/b-search/sang?word=sivan(拼接上?word=sivan)，回显sivan
   
3. 之后我们每次输入http://localhost:2333/b-search/xxx，xxx为任意字符串，都会回显sivan
   

setRequestData函数只会执行一次，中间件函数每一次请求都会执行，所以当我们第一次输入http://localhost:2333/b-search/sang?word=sivan时，word变量被赋值为req.query.word并因为闭包被存储起来，等下一次输入时，由于word = word || xx，会先取存储的word，这就导致了每一次输入都会回显sivan。

改动思路如下截图：虽然闭包还存在，但是这样修改就不会让闭包的变量值被意外篡改，导致意料之外的结果了。

归因

这个问题其实挺严重的，搜索功能直接没用，用户都搜不了内容了，打工人打工不容易，哭泣。也挺有意思的，我只要在链接后面拼接?word=sivan就可以让全球的用户看到同事的名字，扬名立万（不止万了，起码千万了），破涕为笑。

为什么是偶现的呢？因为是集群，有很多服务器节点，每一次请求都可能打到不同的节点上，你输入b-search/xx?word=sivan时，请求只会打到其中一个节点上，只会污染那一个节点上的那个长期存储的word变量。所以被污染的集群节点有问题，没被污染到的集群节点就没问题。

为什么只有x国家站点出现该故障？测试环境没出现过该故障？因为这个故障的触发条件比较苛刻，必须输入b-search/xx?word=sivan才会触发，而正常情况下b搜索链路是不会拼接word=sivan这个query参数的。猜测最开始之时，就是有人在x国家站点因为一些原因输入了http://localhost:2333/b-search/sang?word=sivan引发问题，其他国家站点和测试环境没有输入就没有问题。

触发条件这么苛刻，是谁触发的呢？

• 
  
• 有可能是用户，毕竟几千万用户在用搜索，什么情况在用户那都会发生
  
• 有可能是测试人员，测试在线上环境偶然拼接了这个参数
  
• 有可能是黑客或者友商（概率很低，因为只影响了部分站点）
  
• 前端开发人员，实现了这么一段如此隐晦的bad代码，等哪一天加班太多，心里不爽了，回家敲几个字拼接url访问，网站功能立马下线。
  

删库跑路的梗大家都耳熟能详，我们前端不止是会在svg里面、console里面吐槽公司，我们还可以在node中间层里写bad bad的代码哦，而且还很难测出来，事后归因到前端身上。