This is an automated email from the ASF dual-hosted git repository. liubao pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/incubator-servicecomb-java-chassis.git
commit 58befc96785a7ffe6fdaf965940788af0aa09150 Author: liubao <[email protected]> AuthorDate: Tue Sep 4 10:06:44 2018 +0800 [SCB-887]aysnc servlet timeout is too short and may block container pool when tasks are timeout --- .../common/rest/AbstractRestInvocation.java | 15 +++++++++ .../servicecomb/common/rest/CommonRestConfig.java | 35 ++++++++++++++++++++ .../apache/servicecomb/common/rest/RestConst.java | 2 ++ .../common/rest/RestProducerInvocation.java | 1 + .../common/rest/TestAbstractRestInvocation.java | 1 + .../common/rest/TestCommonRestConfig.java | 37 ++++++++++++++++++++++ .../servicecomb/edge/core/EdgeInvocation.java | 1 + .../transport/rest/servlet/RestAsyncListener.java | 11 +++++-- .../transport/rest/servlet/ServletConfig.java | 14 ++++---- .../rest/servlet/ServletRestDispatcher.java | 2 +- .../rest/servlet/TestRestAsyncListener.java | 4 +-- .../transport/rest/servlet/TestServletConfig.java | 2 +- 12 files changed, 112 insertions(+), 13 deletions(-) diff --git a/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/AbstractRestInvocation.java b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/AbstractRestInvocation.java index 65ef363..53daf7b 100644 --- a/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/AbstractRestInvocation.java +++ b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/AbstractRestInvocation.java @@ -124,6 +124,9 @@ public abstract class AbstractRestInvocation { operationMeta.getExecutor().execute(() -> { synchronized (this.requestEx) { try { + if (isInQueueTimeout()) { + throw new InvocationException(Status.INTERNAL_SERVER_ERROR, "Timeout when processing the request."); + } if (requestEx.getAttribute(RestConst.REST_REQUEST) != requestEx) { // already timeout // in this time, request maybe recycled and reused by web container, do not use requestEx @@ -142,6 +145,18 @@ public abstract class AbstractRestInvocation { }); } + private boolean isInQueueTimeout() { + Object timeout = requestEx.getAttribute(RestConst.REST_REQUEST_IN_QUEUE_TIME); + if (timeout != null) { + if (System.currentTimeMillis() - (Long) timeout + > CommonRestConfig + .getRequestWaitInPoolTimeout()) { + return true; + } + } + return false; + } + protected void runOnExecutor() { invocation.onStartExecute(); diff --git a/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/CommonRestConfig.java b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/CommonRestConfig.java new file mode 100644 index 0000000..a673a5a --- /dev/null +++ b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/CommonRestConfig.java @@ -0,0 +1,35 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.servicecomb.common.rest; + +import com.netflix.config.DynamicLongProperty; +import com.netflix.config.DynamicPropertyFactory; + +public class CommonRestConfig { + public static final String KEY_SERVICECOMB_REQUEST_WAIT_IN_POOL_TIMEOUT = "servicecomb.rest.server.requestWaitInPoolTimeout"; + + public static final long DEFAULT_REQUEST_WAIT_IN_POOL_TIMEOUT = 30000; + + private static final DynamicLongProperty requestWaitInPoolTimeoutProperty = + DynamicPropertyFactory.getInstance().getLongProperty(KEY_SERVICECOMB_REQUEST_WAIT_IN_POOL_TIMEOUT, + DEFAULT_REQUEST_WAIT_IN_POOL_TIMEOUT); + + public static long getRequestWaitInPoolTimeout() { + return requestWaitInPoolTimeoutProperty.get(); + } +} diff --git a/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestConst.java b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestConst.java index 57b4029..5e917d0 100644 --- a/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestConst.java +++ b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestConst.java @@ -55,6 +55,8 @@ public final class RestConst { public static final String REST_REQUEST = "servicecomb-rest-request"; + public static final String REST_REQUEST_IN_QUEUE_TIME = "servicecomb-rest-request-in-queue-time"; + public static final String CONSUMER_HEADER = "servicecomb-rest-consumer-header"; public static final String READ_STREAM_PART = "servicecomb-readStreamPart"; diff --git a/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestProducerInvocation.java b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestProducerInvocation.java index f3cce62..9c71bae 100644 --- a/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestProducerInvocation.java +++ b/common/common-rest/src/main/java/org/apache/servicecomb/common/rest/RestProducerInvocation.java @@ -40,6 +40,7 @@ public class RestProducerInvocation extends AbstractRestInvocation { this.responseEx = responseEx; this.httpServerFilters = httpServerFilters; requestEx.setAttribute(RestConst.REST_REQUEST, requestEx); + requestEx.setAttribute(RestConst.REST_REQUEST_IN_QUEUE_TIME, System.currentTimeMillis()); try { findRestOperation(); diff --git a/common/common-rest/src/test/java/org/apache/servicecomb/common/rest/TestAbstractRestInvocation.java b/common/common-rest/src/test/java/org/apache/servicecomb/common/rest/TestAbstractRestInvocation.java index dcc6110..2114d5f 100644 --- a/common/common-rest/src/test/java/org/apache/servicecomb/common/rest/TestAbstractRestInvocation.java +++ b/common/common-rest/src/test/java/org/apache/servicecomb/common/rest/TestAbstractRestInvocation.java @@ -739,6 +739,7 @@ public class TestAbstractRestInvocation { Executor executor = new ReactiveExecutor(); requestEx = new AbstractHttpServletRequestForTest(); requestEx.setAttribute(RestConst.REST_REQUEST, requestEx); + requestEx.setAttribute(RestConst.REST_REQUEST_IN_QUEUE_TIME, System.currentTimeMillis()); new Expectations() { { restOperation.getOperationMeta(); diff --git a/common/common-rest/src/test/java/org/apache/servicecomb/common/rest/TestCommonRestConfig.java b/common/common-rest/src/test/java/org/apache/servicecomb/common/rest/TestCommonRestConfig.java new file mode 100644 index 0000000..608a94d --- /dev/null +++ b/common/common-rest/src/test/java/org/apache/servicecomb/common/rest/TestCommonRestConfig.java @@ -0,0 +1,37 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.servicecomb.common.rest; + +import org.apache.servicecomb.foundation.test.scaffolding.config.ArchaiusUtils; +import org.junit.After; +import org.junit.Assert; +import org.junit.Test; + +public class TestCommonRestConfig { + @After + public void teanDown() { + ArchaiusUtils.resetConfig(); + } + + @Test + public void testTimeoutConfig() { + Assert.assertEquals(CommonRestConfig.getRequestWaitInPoolTimeout(), 30000); + ArchaiusUtils.setProperty(CommonRestConfig.KEY_SERVICECOMB_REQUEST_WAIT_IN_POOL_TIMEOUT, 50000); + Assert.assertEquals(CommonRestConfig.getRequestWaitInPoolTimeout(), 50000); + } +} diff --git a/edge/edge-core/src/main/java/org/apache/servicecomb/edge/core/EdgeInvocation.java b/edge/edge-core/src/main/java/org/apache/servicecomb/edge/core/EdgeInvocation.java index 742762a..ef5e69c 100644 --- a/edge/edge-core/src/main/java/org/apache/servicecomb/edge/core/EdgeInvocation.java +++ b/edge/edge-core/src/main/java/org/apache/servicecomb/edge/core/EdgeInvocation.java @@ -62,6 +62,7 @@ public class EdgeInvocation extends AbstractRestInvocation { this.routingContext = context; this.httpServerFilters = httpServerFilters; requestEx.setAttribute(RestConst.REST_REQUEST, requestEx); + requestEx.setAttribute(RestConst.REST_REQUEST_IN_QUEUE_TIME, System.currentTimeMillis()); } public void edgeInvoke() { diff --git a/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/RestAsyncListener.java b/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/RestAsyncListener.java index b2bcd7f..3e2c9db 100644 --- a/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/RestAsyncListener.java +++ b/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/RestAsyncListener.java @@ -26,6 +26,7 @@ import javax.servlet.ServletRequest; import javax.servlet.ServletResponse; import javax.servlet.http.HttpServletResponse; import javax.ws.rs.core.MediaType; +import javax.ws.rs.core.Response.Status; import org.apache.servicecomb.common.rest.RestConst; import org.apache.servicecomb.foundation.common.utils.JsonUtils; @@ -44,7 +45,7 @@ public class RestAsyncListener implements AsyncListener { static { try { - TIMEOUT_MESSAGE = JsonUtils.writeValueAsString(new CommonExceptionData("TimeOut in Processing")); + TIMEOUT_MESSAGE = JsonUtils.writeValueAsString(new CommonExceptionData("Timeout when processing the request.")); } catch (JsonProcessingException e) { LOGGER.error("Failed to init timeout message.", e); } @@ -63,17 +64,19 @@ public class RestAsyncListener implements AsyncListener { // to avoid concurrent, must lock request ServletRequest request = event.getSuppliedRequest(); HttpServletRequestEx requestEx = (HttpServletRequestEx) request.getAttribute(RestConst.REST_REQUEST); + LOGGER.error("Rest request timeout, method {}, path {}.", requestEx.getMethod(), requestEx.getRequestURI()); + // Waiting till executing in executor done. This operation may block container pool and make timeout requests in executor's + // queue getting executed, and will cause bad performance. So default timeout is setting to -1 to disable timeout. synchronized (requestEx) { ServletResponse response = event.getAsyncContext().getResponse(); if (!response.isCommitted()) { - LOGGER.error("Rest request timeout, method {}, path {}.", requestEx.getMethod(), requestEx.getRequestURI()); // invocation in executor's queue response.setContentType(MediaType.APPLICATION_JSON); // we don't know if developers declared one statusCode in contract // so we use cse inner statusCode here - ((HttpServletResponse) response).setStatus(ExceptionFactory.PRODUCER_INNER_STATUS_CODE); + ((HttpServletResponse) response).setStatus(Status.INTERNAL_SERVER_ERROR.getStatusCode()); PrintWriter out = response.getWriter(); out.write(TIMEOUT_MESSAGE); response.flushBuffer(); @@ -81,6 +84,8 @@ public class RestAsyncListener implements AsyncListener { request.removeAttribute(RestConst.REST_REQUEST); } + + LOGGER.error("Rest request timeout committed, method {}, path {}.", requestEx.getMethod(), requestEx.getRequestURI()); } @Override diff --git a/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletConfig.java b/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletConfig.java index 6f658e7..9993a3d 100644 --- a/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletConfig.java +++ b/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletConfig.java @@ -22,23 +22,25 @@ import com.netflix.config.DynamicPropertyFactory; import com.netflix.config.DynamicStringProperty; public final class ServletConfig { - static final long DEFAULT_TIMEOUT = 3000; + public static final long DEFAULT_ASYN_SERVLET_TIMEOUT = -1; public static final String KEY_SERVLET_URL_PATTERN = "servicecomb.rest.servlet.urlPattern"; public static final String SERVICECOMB_REST_ADDRESS = "servicecomb.rest.address"; - public static final String KEY_SERVICECOMB_REST_SERVER_TIMEOUT = "servicecomb.rest.server.timeout"; + public static final String KEY_SERVICECOMB_ASYC_SERVLET_TIMEOUT = "servicecomb.rest.server.timeout"; public static final String DEFAULT_URL_PATTERN = "/*"; + private static final DynamicLongProperty asyncServletTimeoutProperty = + DynamicPropertyFactory.getInstance().getLongProperty(KEY_SERVICECOMB_ASYC_SERVLET_TIMEOUT, + DEFAULT_ASYN_SERVLET_TIMEOUT); + private ServletConfig() { } - public static long getServerTimeout() { - DynamicLongProperty address = - DynamicPropertyFactory.getInstance().getLongProperty(KEY_SERVICECOMB_REST_SERVER_TIMEOUT, DEFAULT_TIMEOUT); - return address.get(); + public static long getAsyncServletTimeout() { + return asyncServletTimeoutProperty.get(); } public static String getLocalServerAddress() { diff --git a/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletRestDispatcher.java b/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletRestDispatcher.java index 3ec2a76..01dd4b1 100644 --- a/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletRestDispatcher.java +++ b/transports/transport-rest/transport-rest-servlet/src/main/java/org/apache/servicecomb/transport/rest/servlet/ServletRestDispatcher.java @@ -48,7 +48,7 @@ public class ServletRestDispatcher { // 异步场景 final AsyncContext asyncCtx = request.startAsync(); asyncCtx.addListener(restAsyncListener); - asyncCtx.setTimeout(ServletConfig.getServerTimeout()); + asyncCtx.setTimeout(ServletConfig.getAsyncServletTimeout()); HttpServletRequestEx requestEx = new StandardHttpServletRequestEx(request); HttpServletResponseEx responseEx = new StandardHttpServletResponseEx(response); diff --git a/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestRestAsyncListener.java b/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestRestAsyncListener.java index 3af864c..af533ab 100644 --- a/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestRestAsyncListener.java +++ b/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestRestAsyncListener.java @@ -126,8 +126,8 @@ public class TestRestAsyncListener { Assert.assertNull(request.getAttribute(RestConst.REST_REQUEST)); Assert.assertEquals(MediaType.APPLICATION_JSON, contentType); - Assert.assertEquals(ExceptionFactory.PRODUCER_INNER_STATUS_CODE, statusCode); + Assert.assertEquals(500, statusCode); Assert.assertTrue(flushed); - Assert.assertEquals("{\"message\":\"TimeOut in Processing\"}", writer.toString()); + Assert.assertEquals("{\"message\":\"Timeout when processing the request.\"}", writer.toString()); } } diff --git a/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestServletConfig.java b/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestServletConfig.java index fec0968..4b0bda9 100644 --- a/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestServletConfig.java +++ b/transports/transport-rest/transport-rest-servlet/src/test/java/org/apache/servicecomb/transport/rest/servlet/TestServletConfig.java @@ -44,7 +44,7 @@ public class TestServletConfig { @Test public void testGetServerTimeout() { - Assert.assertEquals(ServletConfig.DEFAULT_TIMEOUT, ServletConfig.getServerTimeout()); + Assert.assertEquals(ServletConfig.DEFAULT_ASYN_SERVLET_TIMEOUT, ServletConfig.getAsyncServletTimeout()); } @Test
