美文网首页
记一次SpringBean误用引起的线上并发问题

记一次SpringBean误用引起的线上并发问题

作者: 艺超51iwowo | 来源:发表于2021-08-01 23:08 被阅读0次
    问题背景

    之前和同事一起负责一个新上线产品登录模块,开始的时候处于小流量试运行,没有什么问题。突然从某天开始,部分用户报登录校验失败。该问题排查了很久,最终定位到是并发问题,这里回顾一下。

    出现问题的关键代码
    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暴露的问题。

    1. 对SpringBean的作用域和多线程并发问题认知不够。
    2. 其实当时排查时还有一个问题,就是关键地方的日志不够,这也增加了我们排查定位问题的难度。
    3. 对基础服务,尽可能提前做好压测,提前发现问题。实际上这段出问题的代码已经在线上环境跑了几个月了,如果不是用户访问增加,我们还是无法识别出问题。

    每一次RCA都是宝贵的财富,共勉!

    相关文章

      网友评论

          本文标题:记一次SpringBean误用引起的线上并发问题

          本文链接:https://www.haomeiwen.com/subject/suxdvltx.html