问题背景
之前和同事一起负责一个新上线产品登录模块，开始的时候处于小流量试运行，没有什么问题。突然从某天开始，部分用户报登录校验失败。该问题排查了很久，最终定位到是并发问题，这里回顾一下。
出现问题的关键代码
AuthParams
@Data
@Component
public class AuthParams {
/**
* 用户code
*/
private String code;
/**
* 用户密码
*/
private String pass;
}
由于该类并非简单的Java实体类，还需要依赖其他的SpringBean，所以将该类也标记了@Component注解。有经验的小伙伴可能已经猜出问题所在了。
AuthService
@Service
@Slf4j
public class AuthServiceImpl implements AuthService {
/**
* mock一下user信息
*/
private static final Map<String, String> MOCK_USER = Maps.newHashMap();
static {
MOCK_USER.put("code1", "pass1");
MOCK_USER.put("code2", "pass2");
}
@Override
public boolean checkAuth(AuthParams authParams) {
String code = authParams.getCode();
String pass = authParams.getPass();
boolean checkResult = MOCK_USER.containsKey(code) && MOCK_USER.get(code).equalsIgnoreCase(pass);
if (!checkResult) {
log.error("code:{}, pass:{}, result:{}", code, pass, checkResult);
}
return checkResult;
}
}
这里采用Mock的方式，实际验证服务会依赖第三方统一登录，这里仅仅是为了验证问题。
AuthController
@RestController
@RequestMapping("/auth")
public class AuthController {
@Resource
private AuthService authService;
@Resource
private AuthParams authParams;
@PostMapping(value = "/checkAuth")
public boolean checkAuth(HttpServletRequest httpServletRequest) {
String code = httpServletRequest.getParameter("code");
String pass = httpServletRequest.getParameter("pass");
authParams.setCode(code);
authParams.setPass(pass);
return authService.checkAuth(authParams);
}
}
模拟对外权限认证的Rest服务接口，从Http请求中获取到code+pass，然后进行校验，返回校验结果。
AuthTest
@Slf4j
public class AuthTest {
private static final ExecutorService EXECUTOR_SERVICE = Executors.newFixedThreadPool(100);
private static final RestTemplate REST_TEMPLATE = new RestTemplate();
private static final String URL = "http://127.0.0.1:8080/auth/checkAuth";
public static void main(String[] args) {
// 并发模拟用户登录
for (int i = 0; i < 1; i++) {
EXECUTOR_SERVICE.submit(new Runnable() {
@Override
public void run() {
int random = ThreadLocalRandom.current().nextInt(1, 3);
String code = "code" + random;
String pass = "pass" + random;
HttpHeaders headers = new HttpHeaders();
headers.setContentType(MediaType.APPLICATION_FORM_URLENCODED);
MultiValueMap<String, Object> map = new LinkedMultiValueMap<>();
// 将请求对象转为map，并添加到multiValueMap中
map.add("code", code);
map.add("pass", pass);
HttpEntity<MultiValueMap<String, Object>> httpEntity = new HttpEntity<>(map, headers);
boolean checkResult = REST_TEMPLATE.postForObject(URL, httpEntity, Boolean.class);
log.info("code:{}, pass:{}, checkResult:{}", code, pass, checkResult);
}
});
}
}
}
说明: 上述代码会模拟多线程并发访问，传入的code+pass，都是Service层Mock的数据。
问题复现
低并发场景
将AuthTest中的请求次数设置的低一些，比如10，看一下运行结果是正常的。
20:08:26.813 [pool-1-thread-7] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:true
20:08:26.813 [pool-1-thread-3] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:true
20:08:26.814 [pool-1-thread-1] INFO com.yichao.myblogs.controller.AuthTest - code:code1, pass:pass1, checkResult:true
20:08:26.817 [pool-1-thread-9] INFO com.yichao.myblogs.controller.AuthTest - code:code1, pass:pass1, checkResult:true
20:08:26.818 [pool-1-thread-6] INFO com.yichao.myblogs.controller.AuthTest - code:code1, pass:pass1, checkResult:true
20:08:26.820 [pool-1-thread-5] INFO com.yichao.myblogs.controller.AuthTest - code:code1, pass:pass1, checkResult:true
20:08:26.823 [pool-1-thread-4] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:true
20:08:26.824 [pool-1-thread-8] INFO com.yichao.myblogs.controller.AuthTest - code:code1, pass:pass1, checkResult:true
20:08:26.824 [pool-1-thread-2] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:true
20:08:26.827 [pool-1-thread-10] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:true
高并发场景
将AuthTest中的请求次数设置高一些，模拟高并发，这里设置1000，看一下运行结果。
20:11:05.829 [pool-1-thread-29] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:false
20:11:05.829 [pool-1-thread-92] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:true
20:11:05.829 [pool-1-thread-42] INFO com.yichao.myblogs.controller.AuthTest - code:code1, pass:pass1, checkResult:false
20:11:05.829 [pool-1-thread-69] INFO com.yichao.myblogs.controller.AuthTest - code:code2, pass:pass2, checkResult:true
可以看到这里就已经出现校验失败的了，明明传入的是正确的参数，为什么会失败了呢。
问题分析
我们都知道SpringBean默认是单例的，那么在线程并发的时候，如果在没有并发控制情况下，对Bean进行修改，势必会引发并发问题。
回到我们的代码
AuthParams通过@Component注解，被Spring管理。
@Component
public class AuthParams
在AuthController中使用的时，直接利用@Resource使用了该Bean
@Resource
private AuthParams authParams;
那么当并发请求了"auth/checkAuth" Rest接口时，就会出现code和pass赋值错乱的问题。
我们在AuthServiceImpl中特意加了一些日志
if (!checkResult) {
log.error("code:{}, pass:{}, result:{}", code, pass, checkResult);
}
2021-08-01 20:11:05.297 ERROR 24804 --- [nio-8080-exec-6] c.y.m.service.impl.AuthServiceImpl : code:code1, pass:pass2, result:false
2021-08-01 20:11:05.297 ERROR 24804 --- [nio-8080-exec-4] c.y.m.service.impl.AuthServiceImpl : code:code1, pass:pass2, result:false
2021-08-01 20:11:05.810 ERROR 24804 --- [io-8080-exec-20] c.y.m.service.impl.AuthServiceImpl : code:code2, pass:pass1, result:false
2021-08-01 20:11:05.810 ERROR 24804 --- [nio-8080-exec-8] c.y.m.service.impl.AuthServiceImpl : code:code2, pass:pass1, result:false
2021-08-01 20:11:06.146 ERROR 24804 --- [io-8080-exec-42] c.y.m.service.impl.AuthServiceImpl : code:code2, pass:pass1, result:false
2021-08-01 20:11:06.146 ERROR 24804 --- [io-8080-exec-55] c.y.m.service.impl.AuthServiceImpl : code:code2, pass:pass1, result:false
2021-08-01 20:11:06.156 ERROR 24804 --- [io-8080-exec-82] c.y.m.service.impl.AuthServiceImpl : code:code1, pass:pass2, result:false
2021-08-01 20:11:06.156 ERROR 24804 --- [nio-8080-exec-1] c.y.m.service.impl.AuthServiceImpl : code:code1, pass:pass2, result:false
2021-08-01 20:11:07.368 ERROR 24804 --- [io-8080-exec-59] c.y.m.service.impl.AuthServiceImpl : code:code1, pass:pass2, result:false
2021-08-01 20:11:07.368 ERROR 24804 --- [io-8080-exec-63] c.y.m.service.impl.AuthServiceImpl : code:code1, pass:pass2, result:false
2021-08-01 20:11:07.670 ERROR 24804 --- [io-8080-exec-36] c.y.m.service.impl.AuthServiceImpl : code:code2, pass:pass1, result:false
2021-08-01 20:11:07.670 ERROR 24804 --- [io-8080-exec-77] c.y.m.service.impl.AuthServiceImpl : code:code2, pass:pass1, result:false
通过上面的日志也看出了存在code和pass不匹配的情况。
问题解决
既然发现了问题，那就快速修复解决吧。我们知道SpringBean实际会有几种不同的scope。
这里着重介绍2类
- singleton(默认)
- 此取值时表明容器中创建时只存在一个实例，所有引用此bean都是单一实例
- prototype
- 允许创建任意多次实例，每个请求方可以得到自己对应的一个对象实例
可以看出，在我们场景中，需要的是prototype类型。那么直接修改AuthParams就可以了吗？
尝试一下吧！
在Controller中加了一条日志，看一下每次调用AuthServiceImpl前的authParams值，是不是每次都是单独的AuthParams
@PostMapping(value = "/checkAuth")
public boolean checkAuth(HttpServletRequest httpServletRequest) {
String code = httpServletRequest.getParameter("code");
String pass = httpServletRequest.getParameter("pass");
log.info("before set, code:{}, pass:{}", authParams.getCode(), authParams.getPass());
authParams.setCode(code);
authParams.setPass(pass);
return authService.checkAuth(authParams);
}
同样以10000并发模拟
2021-08-01 20:31:23.262 INFO 25355 --- [o-8080-exec-229] c.y.myblogs.controller.AuthController : before set, code:code2, pass:pass2
2021-08-01 20:31:23.264 INFO 25355 --- [o-8080-exec-229] c.y.myblogs.controller.AuthController : before set, code:code1, pass:pass1
2021-08-01 20:31:23.267 INFO 25355 --- [o-8080-exec-146] c.y.myblogs.controller.AuthController : before set, code:code2, pass:pass2
奇怪，明明设置了prototype，那么日志打印的地方位于authParams赋值之前，怎么会有值呢。
这里需要特别强调的一点，由于AuthController是单例的，那么由它引入的AuthParams实际还是一个同一个实例，所以到这里还没有解决并发问题。
继续修改。不得不佩服强大的Spring。
@RestController
@RequestMapping("/auth")
@Slf4j
public class AuthController {
@Resource
private AuthService authService;
@Resource
private ApplicationContext applicationContext;
@PostMapping(value = "/checkAuth")
public boolean checkAuth(HttpServletRequest httpServletRequest) {
String code = httpServletRequest.getParameter("code");
String pass = httpServletRequest.getParameter("pass");
AuthParams authParams = applicationContext.getBean(AuthParams.class);
log.info("before set, code:{}, pass:{}", authParams.getCode(), authParams.getPass());
authParams.setCode(code);
authParams.setPass(pass);
return authService.checkAuth(authParams);
}
}
改为直接使用ApplicationContext获取Bean。
这里说明一下，有的小伙伴可能会疑惑，为什么不直接new AuthParams。前面也提到过，由于实际场景中，AuthParams这个类还依赖其他SpringBean做一些处理，所以AuthParams这个类也需要交给Spring管理。直接new的话，就无法使用其他SpringBean了。
再次执行AuthTest
2021-08-01 20:38:54.675 INFO 25704 --- [io-8080-exec-61] c.y.myblogs.controller.AuthController : before set, code:null, pass:null
2021-08-01 20:38:54.675 INFO 25704 --- [io-8080-exec-32] c.y.myblogs.controller.AuthController : before set, code:null, pass:null
2021-08-01 20:38:54.676 INFO 25704 --- [io-8080-exec-22] c.y.myblogs.controller.AuthController : before set, code:null, pass:null
2021-08-01 20:38:54.677 INFO 25704 --- [io-8080-exec-95] c.y.myblogs.controller.AuthController : before set, code:null, pass:null
好开心，终于每次调用前，都是一个全新的AuthParams了，可以解决并发登录验证问题了。
接下来就是RCA(问题根源分析)，全组检讨😭。
问题总结
这个问题感觉还是比较普遍的，因为在我更换项目之后，在另外一个项目中有同学也犯了类似的错误。
总结一下这个case暴露的问题。
- 对SpringBean的作用域和多线程并发问题认知不够。
- 其实当时排查时还有一个问题，就是关键地方的日志不够，这也增加了我们排查定位问题的难度。
- 对基础服务，尽可能提前做好压测，提前发现问题。实际上这段出问题的代码已经在线上环境跑了几个月了，如果不是用户访问增加，我们还是无法识别出问题。
每一次RCA都是宝贵的财富，共勉!
