Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ExecutorMethodInterceptor does not handle InvocationTargetException #1092

Closed
denysivano opened this issue Sep 19, 2018 · 0 comments · Fixed by #1093
Closed

ExecutorMethodInterceptor does not handle InvocationTargetException #1092

denysivano opened this issue Sep 19, 2018 · 0 comments · Fixed by #1093
Labels
Milestone

Comments

@denysivano
Copy link
Contributor

denysivano commented Sep 19, 2018

Spring Cloud Sleuth provides functionality for wrapping instances of Executor and bind a copy of current trace context to another thread to make it accessible from running task. But it looks like there is a bug that changes the behaviour when trying to submit task to filled Executor, because instead of TaskRejectedException (RejectedExecutionException), we receive UndeclaredThrowableException.

Consider sample application:

Application.java

package com.example.spring.cloud.sleuth.exception;

import java.lang.reflect.UndeclaredThrowableException;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.core.task.TaskExecutor;
import org.springframework.core.task.TaskRejectedException;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@SpringBootApplication
public class Application {

    private static final Logger LOGGER = LoggerFactory.getLogger(Application.class);

    private final TaskExecutor taskExecutor;

    public Application(TaskExecutor taskExecutor) {
        this.taskExecutor = taskExecutor;
    }

    @GetMapping
    public String test() {
        try {
            taskExecutor.execute(() -> sneakySleep(1000));
            // this will be rejected
            taskExecutor.execute(() -> sneakySleep(1000));
            return "Hello World!";
        } catch (TaskRejectedException ex) {
            LOGGER.warn("Task rejected", ex);
            return ex.getClass().getSimpleName();
        } catch (UndeclaredThrowableException ex) {
            LOGGER.warn("UndeclaredThrowableException received", ex);
            return ex.getClass().getSimpleName();
        }
    }

    private void sneakySleep(long millis) {
        try {
            Thread.sleep(millis);
        } catch (InterruptedException ex) {
            Thread.currentThread().interrupt();
        }
    }

    public static void main(String[] args) {
        SpringApplication.run(Application.class, args);
    }

    @Configuration
    public static class Config {

        @Bean
        public TaskExecutor taskExecutor() {
            ThreadPoolTaskExecutor taskExecutor = new ThreadPoolTaskExecutor();
            taskExecutor.setCorePoolSize(1);
            taskExecutor.setMaxPoolSize(1);
            taskExecutor.setQueueCapacity(0);
            return taskExecutor;
        }
    }
}

pom.xml

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.0.4.RELEASE</version>
        <relativePath/>
    </parent>
    <groupId>com.example</groupId>
    <artifactId>spring-cloud-sleuth-exception</artifactId>
    <version>1.0.0</version>
    <packaging>jar</packaging>
    <dependencyManagement>
        <dependencies>
            <dependency>
                <groupId>org.springframework.cloud</groupId>
                <artifactId>spring-cloud-dependencies</artifactId>
                <version>Finchley.SR1</version>
                <type>pom</type>
                <scope>import</scope>
            </dependency>
        </dependencies>
    </dependencyManagement>
    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-starter-sleuth</artifactId>
        </dependency>
    </dependencies>
</project>

When spring-cloud-starter-sleuth dependency is removed or spring.sleuth.async.enabled=false property is added, a TaskRejectedException message will be returned on HTTP request:

2018-09-19 19:02:37.784  WARN 31461 --- [nio-8080-exec-1] c.e.s.c.sleuth.exception.Application     : Task rejected

org.springframework.core.task.TaskRejectedException: Executor [java.util.concurrent.ThreadPoolExecutor@3f18fde0[Running, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]] did not accept task: com.example.spring.cloud.sleuth.exception.Application$$Lambda$320/90355657@2487f435
	at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:317) ~[spring-context-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at com.example.spring.cloud.sleuth.exception.Application.test(Application.java:34) ~[classes/:na]
	...
Caused by: java.util.concurrent.RejectedExecutionException: Task com.example.spring.cloud.sleuth.exception.Application$$Lambda$320/90355657@2487f435 rejected from java.util.concurrent.ThreadPoolExecutor@3f18fde0[Running, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047) ~[na:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823) [na:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369) [na:1.8.0_121]
	at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:314) ~[spring-context-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	... 55 common frames omitted

But with ExecutorBeanPostProcessor being used, an UndeclaredThrowableException message will be returned:

2018-09-19 19:00:47.156  WARN [-,bb87832a01adccf6,bb87832a01adccf6,false] 31296 --- [nio-8080-exec-5] c.e.s.c.sleuth.exception.Application     : UndeclaredThrowableException received

java.lang.reflect.UndeclaredThrowableException: null
	at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor$$EnhancerBySpringCGLIB$$32afee45.execute(<generated>) ~[spring-context-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at com.example.spring.cloud.sleuth.exception.Application.test(Application.java:32) ~[classes/:na]
	...
Caused by: java.lang.reflect.InvocationTargetException: null
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_121]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_121]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_121]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_121]
	at org.springframework.cloud.sleuth.instrument.async.ExecutorMethodInterceptor.invoke(ExecutorBeanPostProcessor.java:127) ~[spring-cloud-sleuth-core-2.0.1.RELEASE.jar:2.0.1.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	... 62 common frames omitted
Caused by: org.springframework.core.task.TaskRejectedException: Executor [java.util.concurrent.ThreadPoolExecutor@7101c622[Running, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 2]] did not accept task: org.springframework.cloud.sleuth.instrument.async.TraceRunnable@741cd618
	at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:317) ~[spring-context-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.cloud.sleuth.instrument.async.LazyTraceThreadPoolTaskExecutor.execute(LazyTraceThreadPoolTaskExecutor.java:60) ~[spring-cloud-sleuth-core-2.0.1.RELEASE.jar:2.0.1.RELEASE]
	... 69 common frames omitted
Caused by: java.util.concurrent.RejectedExecutionException: Task org.springframework.cloud.sleuth.instrument.async.TraceRunnable@741cd618 rejected from java.util.concurrent.ThreadPoolExecutor@7101c622[Running, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 2]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047) ~[na:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823) [na:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369) [na:1.8.0_121]
	at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:314) ~[spring-context-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	... 70 common frames omitted

This happens because an instance of checked exception (InvocationTargetException) is being thrown while proxying calls to Executor methods. Because Executor's and TaskExecutor's methods don't declare any checked exceptions, an InvocationTargetException is being wrapped into UndeclaredThrowableException.

Take a look at how ExecutorMethodInterceptor invokes the target method:

	@Override public Object invoke(MethodInvocation invocation)
			throws Throwable {
		Executor executor = executor(this.beanFactory, this.delegate);
		Method methodOnTracedBean = getMethod(invocation, executor);
		if (methodOnTracedBean != null) {
			return methodOnTracedBean.invoke(executor, invocation.getArguments());
		}
		return invocation.proceed();
	}

Call to methodOnTracedBean.invoke(executor, invocation.getArguments()) throws an InvocationTargetException.

Would it be better to catch checked InvocationTargetException and re-throw it's cause (if present)?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants