Spring @Async annotated method acts synchronously?

I wrote a Spring MVC demo for demonstrating this:

Controller:

@Controller
public class HomeController {
	private Logger logger = LoggerFactory.getLogger(getClass());

	@RequestMapping({ "/", "/home" })
	public String showHomePage(Map<String, Object> model) {
		logger.info("1: " + System.currentTimeMillis());
		asyncTest();
		logger.info("2: " + System.currentTimeMillis());
		return "home";
	}
	
	@Async
	private void asyncTest(){
		try {
			logger.info("3: " + System.currentTimeMillis());
			Thread.sleep(2000);
		} catch (InterruptedException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}
		logger.info("4: " + System.currentTimeMillis());
	}
}

Application Context configuration:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
	xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:context="http://www.springframework.org/schema/context"
	xmlns:jdbc="http://www.springframework.org/schema/jdbc" xmlns:p="http://www.springframework.org/schema/p"
	xmlns:util="http://www.springframework.org/schema/util" xmlns:tx="http://www.springframework.org/schema/tx"
	xmlns:mvc="http://www.springframework.org/schema/mvc" xmlns:task="http://www.springframework.org/schema/task"
	xsi:schemaLocation="http://www.springframework.org/schema/jdbc
		http://www.springframework.org/schema/jdbc/spring-jdbc-3.0.xsd
		http://www.springframework.org/schema/mvc
		http://www.springframework.org/schema/mvc/spring-mvc-3.0.xsd
		http://www.springframework.org/schema/beans
		http://www.springframework.org/schema/beans/spring-beans-3.0.xsd
		http://www.springframework.org/schema/tx
		http://www.springframework.org/schema/tx/spring-tx-3.0.xsd
		http://www.springframework.org/schema/context
		http://www.springframework.org/schema/context/spring-context-3.0.xsd
		http://www.springframework.org/schema/util
		http://www.springframework.org/schema/util/spring-util-3.0.xsd
		http://www.springframework.org/schema/task
		http://www.springframework.org/schema/task/spring-task-3.1.xsd">
	<mvc:resources mapping="resources/**" location="/resources/" />
	<mvc:annotation-driven />

	<bean id="executorService" class="java.util.concurrent.Executors"
		factory-method="newFixedThreadPool">
		<constructor-arg value="10" />
	</bean>

	<task:executor id="threadPoolTaskExecutor" pool-size="10" />

	<task:annotation-driven executor="executorService" />

	<context:component-scan base-package="com.derek" />

	<bean
		class="org.springframework.web.servlet.view.InternalResourceViewResolver">
		<property name="prefix" value="/WEB-INF/views/" />
		<property name="suffix" value=".jsp" />
	</bean>
</beans>

For task configuration, I saw 3 versions of configuration, I tried them all, but the results are no different, version 1 is as shown above,

version 2:

<task:annotation-driven />

version 3:

<task:executor id="WhifExecutor" pool-size="10"/>
<task:annotation-driven executor="WhifExecutor" />

I experimented with these configurations, but the results all are like this:

07:49:41.962 [http-bio-8080-exec-3] INFO  com.derek.demo.mvc.HomeController - 1: 1367711381956
07:49:41.966 [http-bio-8080-exec-3] INFO  com.derek.demo.mvc.HomeController - 3: 1367711381966
07:49:43.966 [http-bio-8080-exec-3] INFO  com.derek.demo.mvc.HomeController - 4: 1367711383966
07:49:43.966 [http-bio-8080-exec-3] INFO  com.derek.demo.mvc.HomeController - 2: 1367711383966

Frustrated! I see no asynchronous behavior here. Why?

At last, I got the answer on http://stackoverflow.com/questions/5300833/sending-email-with-spring-in-a-new-thread-issue

There are some limitations you need to pay respect to:
The annotated method must belong to a spring bean;
The invocation of the annotated method must be executed from a different Spring Bean (if you are using standard Spring AOP).

Thereby, I restructured my code as this:

@Controller
public class HomeController {
	private Logger logger = LoggerFactory.getLogger(getClass());
	
	@Autowired
	private AsyncService asyncService;

	@RequestMapping({ "/", "/home" })
	public String showHomePage(Map<String, Object> model) {
		logger.info("1: " + System.currentTimeMillis());
		asyncService.asyncTest();
		logger.info("2: " + System.currentTimeMillis());
		return "home";
	}
}

@Service
public class AsyncService {
	private Logger logger = LoggerFactory.getLogger(getClass());

	@Async
	public void asyncTest() {
		try {
			logger.info("3: " + System.currentTimeMillis());
			Thread.sleep(2000);
		} catch (InterruptedException e) {
			// TODO Auto-generated catch block
			e.printStackTrace();
		}
		logger.info("4: " + System.currentTimeMillis());
	}
}

Now, everything goes well:

18:17:34.958 [http-bio-8080-exec-10] INFO  com.derek.demo.mvc.HomeController - 1: 1367749054953
18:17:34.967 [http-bio-8080-exec-10] INFO  com.derek.demo.mvc.HomeController - 2: 1367749054967
18:17:34.995 [pool-4-thread-1] INFO  com.derek.demo.mvc.AsyncService - 3: 1367749054995
18:17:37.002 [pool-4-thread-1] INFO  com.derek.demo.mvc.AsyncService - 4: 1367749057002

Obviously, it behaves asynchronously. Great!