spring scope与线程之间的关系？

Question

spring scope与线程之间的关系怎么解释？有没有什么关联性？

问题如下：
spring scope 模拟为单例模式，则认为多次请求同一个地址时，是按顺序执行，如同时执行 5次 a的test方法，会按顺序执行

如下代码：

    @GetMapping("test1")
    public Object test1(HttpServletRequest request) throws InterruptedException {
        logger.error("this:{},in time:{}", this.toString(), System.currentTimeMillis());
        String sleepFlag = request.getParameter("sleep");
        if ("on".equalsIgnoreCase(sleepFlag)) {
            Thread.currentThread().sleep(10000l);
            logger.error("return time:{}", System.currentTimeMillis());
            return "sleep 10s";
        }
        logger.error("return time:{}", System.currentTimeMillis());
        return "no sleep";
    }

1. http://localhost:8080/test1?sleep=on
2. http://localhost:8080/test1

各执行两次，执行顺序为1-1、1-2、2-1、2-2，打印结果如下：

2018-03-26 16:56:03.793 ERROR 16292 --- [nio-8080-exec-1] c.e.m.web.controller.UserController      : this:com.example.multimodule.web.controller.UserController@7f74f276,in time:1522054563793
2018-03-26 16:56:07.349 ERROR 16292 --- [nio-8080-exec-2] c.e.m.web.controller.UserController      : this:com.example.multimodule.web.controller.UserController@7f74f276,in time:1522054567349
2018-03-26 16:56:07.349 ERROR 16292 --- [nio-8080-exec-2] c.e.m.web.controller.UserController      : return time:1522054567349
2018-03-26 16:56:09.438 ERROR 16292 --- [nio-8080-exec-4] c.e.m.web.controller.UserController      : this:com.example.multimodule.web.controller.UserController@7f74f276,in time:1522054569437
2018-03-26 16:56:09.438 ERROR 16292 --- [nio-8080-exec-4] c.e.m.web.controller.UserController      : return time:1522054569438
2018-03-26 16:56:13.797 ERROR 16292 --- [nio-8080-exec-1] c.e.m.web.controller.UserController      : return time:1522054573797
2018-03-26 16:56:13.801 ERROR 16292 --- [nio-8080-exec-8] c.e.m.web.controller.UserController      : this:com.example.multimodule.web.controller.UserController@7f74f276,in time:1522054573801
2018-03-26 16:56:23.801 ERROR 16292 --- [nio-8080-exec-8] c.e.m.web.controller.UserController      : return time:1522054583801

结果: 执行过程中 1-1与1-2符合预期结果，即第一次执行完成以后休眠10s执行第二次，但1-1与2-1中间并没有休眠过程（有时间差是因为手工执行的），并且不管controller是否设置为scope=prototype，执行结果都是一样的

求解释

Answer 1

我个人认为是你把单例和线程安全搞混了，单例并不意味着线程安全，多线程同时访问单例同样存在并发问题，除非你手动加锁。下面通过一个例子说明，你觉得最后 count 会是多少？

public class Demo {
    private int count;

    public void add() {
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        this.count++;
    }

    public static void main(String[] args) {
        Demo d = new Demo();

        // 8个线程同时访问同一个 demo
        new Thread(() -> {d.add();}).start();
        new Thread(() -> {d.add();}).start();
        new Thread(() -> {d.add();}).start();
        new Thread(() -> {d.add();}).start();
        new Thread(() -> {d.add();}).start();
        new Thread(() -> {d.add();}).start();
        new Thread(() -> {d.add();}).start();
        new Thread(() -> {d.add();}).start();

        // 主线程休眠 2 s ，等其他线程执行结束
        try {
            Thread.sleep(2000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        System.out.println(d.count);
    }
}

Answer 2

@oxf1992

按照你所说，在controller 中执行休眠的时候，符合差不多同时执行的规律
但是如果在controller 调用service，service执行休眠的时候，两个间隔时间比较长，但又小于休眠时间，具体代码如下

@RestController
@RequestMapping("/test")
public class TestController {
    private static final Logger logger = LoggerFactory.getLogger(TestController.class);
    @Autowired
    private IUserService userService;

    @GetMapping("/user")
    public Object testUser() {
        logger.info("testController:{}", this.toString());
        logger.info("userService:{}", userService.toString());
        userService.get(1l);
        return "ok";
    }

    @RequestMapping("/foo2")
    public Object foo2(HttpServletRequest request) throws InterruptedException {
        String param = request.getParameter("p");
        logger.error("param:{}", param);
        long start = System.currentTimeMillis();
        Thread.sleep(10000);
        long end = System.currentTimeMillis();
        logger.error("time:{}", end - start);
        return end - start;
    }
}


    @Override
    public void get(Long id) {
        logger.error("get start...{}", this.toString());
        try {
            Thread.sleep(30000l);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        logger.error("get end...{}", this.toString());
    }

结果如下：

2018-03-28 15:53:04.559  INFO 21776 --- [io-8080-exec-10] c.e.m.web.controller.TestController      : testController:com.example.multimodule.web.controller.TestController@189ebbd
2018-03-28 15:53:04.559  INFO 21776 --- [io-8080-exec-10] c.e.m.web.controller.TestController      : userService:com.example.multimodule.service.service.impl.UserServiceImpl@2a12ba65
2018-03-28 15:53:04.559 ERROR 21776 --- [io-8080-exec-10] c.e.m.s.service.impl.UserServiceImpl     : get start...com.example.multimodule.service.service.impl.UserServiceImpl@2a12ba65
2018-03-28 15:53:25.665  INFO 21776 --- [nio-8080-exec-4] c.e.m.web.controller.TestController      : testController:com.example.multimodule.web.controller.TestController@189ebbd
2018-03-28 15:53:25.665  INFO 21776 --- [nio-8080-exec-4] c.e.m.web.controller.TestController      : userService:com.example.multimodule.service.service.impl.UserServiceImpl@2a12ba65
2018-03-28 15:53:25.665 ERROR 21776 --- [nio-8080-exec-4] c.e.m.s.service.impl.UserServiceImpl     : get start...com.example.multimodule.service.service.impl.UserServiceImpl@2a12ba65
2018-03-28 15:53:34.559 ERROR 21776 --- [io-8080-exec-10] c.e.m.s.service.impl.UserServiceImpl     : get end...com.example.multimodule.service.service.impl.UserServiceImpl@2a12ba65
2018-03-28 15:53:55.665 ERROR 21776 --- [nio-8080-exec-4] c.e.m.s.service.impl.UserServiceImpl     : get end...com.example.multimodule.service.service.impl.UserServiceImpl@2a12ba65
2018-03-28 15:54:01.853 ERROR 21776 --- [nio-8080-exec-8] c.e.m.web.controller.TestController      : param:aaaaa
2018-03-28 15:54:03.788 ERROR 21776 --- [nio-8080-exec-5] c.e.m.web.controller.TestController      : param:bbbb
2018-03-28 15:54:11.854 ERROR 21776 --- [nio-8080-exec-8] c.e.m.web.controller.TestController      : time:10000
2018-03-28 15:54:13.788 ERROR 21776 --- [nio-8080-exec-5] c.e.m.web.controller.TestController      : time:10000

可以看到两次执行foo2请求，基本是同时执行，但两次执行user，中间间隔时间较长