序

本文主要記錄一下spring schedule調(diào)度異常芥驳。

相關(guān)背景

• 調(diào)度配置

    @Scheduled(cron = "0 0 22 * * ?")
    public void doSomething() throws InterruptedException {
        //remote http call
    }

• 問題

從某一天開始這個調(diào)度沒有執(zhí)行

排查

查看日志

查看了下日志友扰，沒有拋異常

查看系統(tǒng)狀態(tài)

查了那個時間點的系統(tǒng)指標(biāo)诡蜓，沒啥異常，附近有個young gc，不過也就80ms

jstack

jstack -l pid

初步看來線程堆棧，沒看到有啥死鎖信息

假設(shè)

一開始有點懷疑是不是spring schedule因為線程池線程不夠酷誓，或者前面幾個時間點的定時任務(wù)執(zhí)行時間過長導(dǎo)致這個調(diào)度任務(wù)一直無法執(zhí)行，或者導(dǎo)致了misfire的情況态坦。

后來線下單獨試圖去復(fù)現(xiàn)盐数，發(fā)現(xiàn)spring schedule只要有放入隊列，即使misfire了伞梯，過了設(shè)定的調(diào)度時間點娘扩，還是會執(zhí)行的。就單單這個定時任務(wù)有問題壮锻，其他的定時任務(wù)每天都執(zhí)行好好的琐旁。

ScheduledThreadPoolExecutor

java/util/concurrent/ScheduledThreadPoolExecutor.java

public ScheduledThreadPoolExecutor(int corePoolSize,
                                       ThreadFactory threadFactory,
                                       RejectedExecutionHandler handler) {
        super(corePoolSize, Integer.MAX_VALUE, 0, NANOSECONDS,
              new DelayedWorkQueue(), threadFactory, handler);
}

public ThreadPoolExecutor(int corePoolSize,
                              int maximumPoolSize,
                              long keepAliveTime,
                              TimeUnit unit,
                              BlockingQueue<Runnable> workQueue,
                              ThreadFactory threadFactory,
                              RejectedExecutionHandler handler) {
        if (corePoolSize < 0 ||
            maximumPoolSize <= 0 ||
            maximumPoolSize < corePoolSize ||
            keepAliveTime < 0)
            throw new IllegalArgumentException();
        if (workQueue == null || threadFactory == null || handler == null)
            throw new NullPointerException();
        this.corePoolSize = corePoolSize;
        this.maximumPoolSize = maximumPoolSize;
        this.workQueue = workQueue;
        this.keepAliveTime = unit.toNanos(keepAliveTime);
        this.threadFactory = threadFactory;
        this.handler = handler;
    }

這里創(chuàng)建的是DelayedWorkQueue

ThreadPoolExecutor#runWorker

java/util/concurrent/ThreadPoolExecutor.java

final void runWorker(Worker w) {
        Thread wt = Thread.currentThread();
        Runnable task = w.firstTask;
        w.firstTask = null;
        w.unlock(); // allow interrupts
        boolean completedAbruptly = true;
        try {
            while (task != null || (task = getTask()) != null) {
                w.lock();
                // If pool is stopping, ensure thread is interrupted;
                // if not, ensure thread is not interrupted.  This
                // requires a recheck in second case to deal with
                // shutdownNow race while clearing interrupt
                if ((runStateAtLeast(ctl.get(), STOP) ||
                     (Thread.interrupted() &&
                      runStateAtLeast(ctl.get(), STOP))) &&
                    !wt.isInterrupted())
                    wt.interrupt();
                try {
                    beforeExecute(wt, task);
                    Throwable thrown = null;
                    try {
                        task.run();
                    } catch (RuntimeException x) {
                        thrown = x; throw x;
                    } catch (Error x) {
                        thrown = x; throw x;
                    } catch (Throwable x) {
                        thrown = x; throw new Error(x);
                    } finally {
                        afterExecute(task, thrown);
                    }
                } finally {
                    task = null;
                    w.completedTasks++;
                    w.unlock();
                }
            }
            completedAbruptly = false;
        } finally {
            processWorkerExit(w, completedAbruptly);
        }
    }

這里調(diào)用了task.run();

ScheduledThreadPoolExecutor.ScheduledFutureTask#run

        /**
         * Overrides FutureTask version so as to reset/requeue if periodic.
         */
        public void run() {
            boolean periodic = isPeriodic();
            if (!canRunInCurrentRunState(periodic))
                cancel(false);
            else if (!periodic)
                ScheduledFutureTask.super.run();
            else if (ScheduledFutureTask.super.runAndReset()) {
                setNextRunTime();
                reExecutePeriodic(outerTask);
            }
        }
        
    /**
     * Requeues a periodic task unless current run state precludes it.
     * Same idea as delayedExecute except drops task rather than rejecting.
     *
     * @param task the task
     */
    void reExecutePeriodic(RunnableScheduledFuture<?> task) {
        if (canRunInCurrentRunState(true)) {
            super.getQueue().add(task);
            if (!canRunInCurrentRunState(true) && remove(task))
                task.cancel(false);
            else
                ensurePrestart();
        }
    }

這里每當(dāng)執(zhí)行完之后判斷下一次的執(zhí)行時間，然后重新放入隊列猜绣，這樣完成周期性調(diào)度灰殴。

看到這里再去仔細看來下日志，發(fā)現(xiàn)有一天的調(diào)度任務(wù)執(zhí)行了沒有打印結(jié)束日志掰邢，那么開始懷疑是不是這個定時任務(wù)一直沒有執(zhí)行完牺陶，導(dǎo)致接下來的幾天的調(diào)度都一直沒法放入隊列執(zhí)行。

線程堆棧

"job-async-5" #44 prio=5 os_prio=0 tid=0x00007fb9aa7a4000 nid=0x42 runnable [0x00007fb98dfee000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
    at java.net.SocketInputStream.read(SocketInputStream.java:170)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    - locked <0x00000006c6167e60> (a java.io.BufferedInputStream)
    at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:704)
    at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:647)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1536)
    - locked <0x00000006c6167eb8> (a sun.net.www.protocol.http.HttpURLConnection)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1441)
    - locked <0x00000006c6167eb8> (a sun.net.www.protocol.http.HttpURLConnection)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
    at org.springframework.http.client.SimpleClientHttpResponse.getRawStatusCode(SimpleClientHttpResponse.java:52)
    at org.springframework.cloud.netflix.metrics.DefaultMetricsTagProvider.clientHttpRequestTags(DefaultMetricsTagProvider.java:44)
    at org.springframework.cloud.netflix.metrics.MetricsClientHttpRequestInterceptor.intercept(MetricsClientHttpRequestInterceptor.java:75)
    at org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:86)
    at org.springframework.http.client.InterceptingClientHttpRequest.executeInternal(InterceptingClientHttpRequest.java:70)
    at org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)
    at org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:652)
    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:613)
    at org.springframework.web.client.RestTemplate.postForEntity(RestTemplate.java:407)
    at org.springframework.web.client.RestTemplate$$FastClassBySpringCGLIB$$aa4e9ed0.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:721)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
    at org.springframework.cloud.netflix.metrics.RestTemplateUrlTemplateCapturingAspect.captureUrlTemplate(RestTemplateUrlTemplateCapturingAspect.java:33)
    at sun.reflect.GeneratedMethodAccessor235.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:629)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:618)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656)
    at org.springframework.web.client.RestTemplate$$EnhancerBySpringCGLIB$$68afae5e.postForEntity(<generated>)

又在查看了沒有結(jié)束的定時任務(wù)的線程堆棧辣之，發(fā)現(xiàn)確實是卡住了掰伸，不過這里線程狀態(tài)一直是RUNNABLE.

SocketInputStream.socketRead0

罪魁禍?zhǔn)拙驮谶@個SocketInputStream.socketRead0。不過有個疑問怀估，默認RestTemplate應(yīng)該是有設(shè)置超時時間才對的狮鸭。

spring-web-4.3.7.RELEASE-sources.jar!/org/springframework/web/client/RestTemplate.java

protected <T> T doExecute(URI url, HttpMethod method, RequestCallback requestCallback,
            ResponseExtractor<T> responseExtractor) throws RestClientException {

        Assert.notNull(url, "'url' must not be null");
        Assert.notNull(method, "'method' must not be null");
        ClientHttpResponse response = null;
        try {
            ClientHttpRequest request = createRequest(url, method);
            if (requestCallback != null) {
                requestCallback.doWithRequest(request);
            }
            response = request.execute();
            handleResponse(url, method, response);
            if (responseExtractor != null) {
                return responseExtractor.extractData(response);
            }
            else {
                return null;
            }
        }
        catch (IOException ex) {
            String resource = url.toString();
            String query = url.getRawQuery();
            resource = (query != null ? resource.substring(0, resource.indexOf(query) - 1) : resource);
            throw new ResourceAccessException("I/O error on " + method.name() +
                    " request for \"" + resource + "\": " + ex.getMessage(), ex);
        }
        finally {
            if (response != null) {
                response.close();
            }
        }
    }

這里調(diào)用了createRequest

spring-web-4.3.7.RELEASE-sources.jar!/org/springframework/http/client/support/HttpAccessor.java

private ClientHttpRequestFactory requestFactory = new SimpleClientHttpRequestFactory();

protected ClientHttpRequest createRequest(URI url, HttpMethod method) throws IOException {
        ClientHttpRequest request = getRequestFactory().createRequest(url, method);
        if (logger.isDebugEnabled()) {
            logger.debug("Created " + method.name() + " request for \"" + url + "\"");
        }
        return request;
    }

默認是SimpleClientHttpRequestFactory
spring-web-4.3.7.RELEASE-sources.jar!/org/springframework/http/client/SimpleClientHttpRequestFactory.java

    private int connectTimeout = -1;

    private int readTimeout = -1;

@Override
    public ClientHttpRequest createRequest(URI uri, HttpMethod httpMethod) throws IOException {
        HttpURLConnection connection = openConnection(uri.toURL(), this.proxy);
        prepareConnection(connection, httpMethod.name());

        if (this.bufferRequestBody) {
            return new SimpleBufferingClientHttpRequest(connection, this.outputStreaming);
        }
        else {
            return new SimpleStreamingClientHttpRequest(connection, this.chunkSize, this.outputStreaming);
        }
    }

    /**
     * Template method for preparing the given {@link HttpURLConnection}.
     * <p>The default implementation prepares the connection for input and output, and sets the HTTP method.
     * @param connection the connection to prepare
     * @param httpMethod the HTTP request method ({@code GET}, {@code POST}, etc.)
     * @throws IOException in case of I/O errors
     */
    protected void prepareConnection(HttpURLConnection connection, String httpMethod) throws IOException {
        if (this.connectTimeout >= 0) {
            connection.setConnectTimeout(this.connectTimeout);
        }
        if (this.readTimeout >= 0) {
            connection.setReadTimeout(this.readTimeout);
        }

        connection.setDoInput(true);

        if ("GET".equals(httpMethod)) {
            connection.setInstanceFollowRedirects(true);
        }
        else {
            connection.setInstanceFollowRedirects(false);
        }

        if ("POST".equals(httpMethod) || "PUT".equals(httpMethod) ||
                "PATCH".equals(httpMethod) || "DELETE".equals(httpMethod)) {
            connection.setDoOutput(true);
        }
        else {
            connection.setDoOutput(false);
        }

        connection.setRequestMethod(httpMethod);
    }

這里prepareConnection進行了超時設(shè)置合搅，不過connectTimeout和readTimeout默認都是-1，相當(dāng)于永遠阻塞歧蕉。這就是出問題的地方灾部。

修復(fù)問題

設(shè)置timeout

創(chuàng)建resttemplate的時候，指定設(shè)置好超時時間的ClientHttpRequestFactory

• SimpleClientHttpRequestFactory
  如果沒有依賴http client惯退，則默認使用的是SimpleClientHttpRequestFactory

    @Bean
    public RestTemplate restTemplate() {
        SimpleClientHttpRequestFactory clientHttpRequestFactory = new SimpleClientHttpRequestFactory();
        clientHttpRequestFactory.setConnectTimeout(30000);
        clientHttpRequestFactory.setReadTimeout(30000);
        RestTemplate restTemplate = new RestTemplate(clientHttpRequestFactory);
        return restTemplate;
    }

注意這里單位是毫秒

• 如果有http client的依賴赌髓，底層使用HttpComponentsClientHttpRequestFactory

    @Bean
    public RestTemplate customRestTemplate(){
        HttpComponentsClientHttpRequestFactory httpRequestFactory = new HttpComponentsClientHttpRequestFactory();
        httpRequestFactory.setConnectionRequestTimeout(3000);
        httpRequestFactory.setConnectTimeout(3000);
        httpRequestFactory.setReadTimeout(3000);

        return new RestTemplate(httpRequestFactory);
    }

設(shè)置了timeout還不行

如果你設(shè)置了timeout，依然還阻塞在SocketInputStream.socketRead0催跪，那么請升級JDK锁蠕，JDK有個bug: SocketInputStream.socketRead0 can hang even with soTimeout set。

doc

• ScheduledExecutorService 定時任務(wù)運行原理
• Thread is blocked when use restTemplate
• java.net.socketinputstream.socketread0 hangs thread
• How to prevent hangs on SocketInputStream.socketRead0 in Java?
• SocketInputStream.socketRead0 can hang even with soTimeout set
• Spring for android RestTemplate 超時設(shè)置
• springboot設(shè)置RestTemplate的超時時間