You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@camel.apache.org by Thomas Günter <Th...@intersys.ch> on 2014/12/02 10:57:33 UTC
Delayed request processing with Camel Restlet 2.14.0
Hi,
we moved a restful application based on the RESTLET component from Camel 2.13.3 to 2.14.0 and discovered severe perfomance problems with the latter version.
Whereas requests with 2.13.3 were countinuously replied within a few (10) milliseconds, with 2.14.0 the requests took longer than 200ms (up to 500ms).
The strange thing is, that the time passes by between the moment the request reaches the server and the moment the first log appears on server side.
Has anyone experienced the same issue or an explanation/solution for this?
Thanks in advance,
Thomas
Client side log:
TEST 02.27.14 - 08:27:26.170 DEBUG c.i.c.h.c.f.FailoverLbHttpClient - Executing request [http://localhost:9000/siggw] to host [http://localhost:9000]
TEST 02.27.14 - 08:27:26.677 DEBUG c.i.s.s.c.r.i.SigGwRsRequestExecutor - Received response from SIGGW [response]
Server side log:
02.12.2014 08:27:26.669 [Thread-2] DEBUG o.r.C.LogService [] [] [] [] - Processing request to: "http://localhost:9000/siggw"
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Call score for the "org.restlet.routing.VirtualHost@7a3c388e" host: 1.0
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Default virtual host selected
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Base URI: "http://localhost:9000". Remaining part: "/siggw"
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Call score for the "/hc" URI pattern: 0.0
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Call score for the "/siggw" URI pattern: 1.0
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Selected route: "/siggw" -> org.apache.camel.component.restlet.MethodBasedRouter@790b3d68
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - 6 characters were matched
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - New base URI: "http://localhost:9000/siggw". No remaining part to match
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Delegating the call to the target Restlet
02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ChallengeAuthenticator [] [] [] [] - Authentication succeeded. Valid credentials provided for identifier: siggw.user.
02.12.2014 08:27:26.671 [Thread-2] DEBUG o.r.C.ChallengeAuthenticator [] [] [] [] - The authentication succeeded for the identifer "siggw.user" using the HTTP_Basic scheme.
02.12.2014 08:27:26.671 [Thread-2] DEBUG c.i.s.s.a.r.r.JsonToMapMessageTransformer [] [] [] [] - Received request: {request1}
02.12.2014 08:27:26.672 [Thread-2] INFO c.i.s.s.a.r.r.JsonToMapMessageTransformer [1] [testClient] [testClient@localhost] [998571731] - Message received: [message1]
02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.r.CommonMessageValidator [1] [testClient] [testClient@localhost] [998571731] - Applying common validations
02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.r.GetInfoRequestValidator [1] [testClient] [testClient@localhost] [998571731] - Executing GetInfoRequestValidator
02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - GsmMap Producer called
02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Message created
02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Requests checked
02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Requested infos prepared
02.12.2014 08:27:26.673 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Sending request
02.12.2014 08:27:26.674 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Request answered successfully
02.12.2014 08:27:26.674 [Thread-2] DEBUG c.i.s.s.a.r.ResponseHandler [1] [testClient] [testClient@localhost] [998571731] - Response Handler called
02.12.2014 08:27:26.674 [Thread-2] INFO c.i.s.s.a.r.ResponseHandler [1] [testClient] [testClient@localhost] [998571731] - Message returned: [message 1]
02.12.2014 08:27:26.675 [Thread-2] DEBUG c.i.s.s.a.r.r.MapMessageToJsonTransformer [] [] [] [] - Returning response: {response1}
02.12.2014 08:27:26.675 [Thread-2] INFO o.r.C.LogService [] [] [] [] - 2014-12-02 08:27:26 127.0.0.1 siggw.user - 9000 POST /siggw - 200 410 341 6 http://localhost:9000 Apache-HttpClient/4.2 (java 1.5) -
TCP-Trace:
86 2014-12-02 09:27:26.171193 127.0.0.1 127.0.0.1 HTTP 601 POST /siggw HTTP/1.1 (application/json)
90 2014-12-02 09:27:26.677193 127.0.0.1 127.0.0.1 HTTP 450 HTTP/1.1 200 OK (application/json)
Restlet component configuration:
<bean id="restlet" class="org.apache.camel.component.restlet.RestletComponent">
<property name="minThreads" value="50" />
<property name="maxThreads" value="50" />
<property name="lowThreads" value="50" />
<property name="maxQueued" value="-1" />
</bean>
<util:map id="realm">
<entry key="siggw.user" value="${route.rest.password}" />
</util:map>
Endpoint configuration:
this.siggwUri = "restlet:http://localhost:" + this.restPort + CommonConstantsA.RS_SIGGW_PATH + "?restletMethod=post&restletRealm=#realm";
Java-Version:
java version "1.7.0_25"
Java(TM) SE Runtime Environment (build 1.7.0_25-b17)
Java HotSpot(TM) 64-Bit Server VM (build 23.25-b01, mixed mode)
Re: Delayed request processing with Camel Restlet 2.14.0
Posted by Claus Ibsen <cl...@gmail.com>.
Hi
I have logged a ticket at restlet to see if they can help. As I
suspects its their async handler that may have a problem
https://github.com/restlet/restlet-framework-java/issues/996
For Camel 2.14.x I am adding back the sync version, so people can
leverage it using synchronous=true.
On Tue, Dec 2, 2014 at 11:36 AM, Claus Ibsen <cl...@gmail.com> wrote:
> Hi
>
> Try set synchronous=true on the restlet uris.
> Also you can try downgraded restlet itself as we upgraded it too.
>
> On Tue, Dec 2, 2014 at 10:57 AM, Thomas Günter
> <Th...@intersys.ch> wrote:
>> Hi,
>>
>> we moved a restful application based on the RESTLET component from Camel 2.13.3 to 2.14.0 and discovered severe perfomance problems with the latter version.
>> Whereas requests with 2.13.3 were countinuously replied within a few (10) milliseconds, with 2.14.0 the requests took longer than 200ms (up to 500ms).
>> The strange thing is, that the time passes by between the moment the request reaches the server and the moment the first log appears on server side.
>>
>> Has anyone experienced the same issue or an explanation/solution for this?
>>
>> Thanks in advance,
>> Thomas
>>
>>
>> Client side log:
>> TEST 02.27.14 - 08:27:26.170 DEBUG c.i.c.h.c.f.FailoverLbHttpClient - Executing request [http://localhost:9000/siggw] to host [http://localhost:9000]
>> TEST 02.27.14 - 08:27:26.677 DEBUG c.i.s.s.c.r.i.SigGwRsRequestExecutor - Received response from SIGGW [response]
>>
>> Server side log:
>> 02.12.2014 08:27:26.669 [Thread-2] DEBUG o.r.C.LogService [] [] [] [] - Processing request to: "http://localhost:9000/siggw"
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Call score for the "org.restlet.routing.VirtualHost@7a3c388e" host: 1.0
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Default virtual host selected
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Base URI: "http://localhost:9000". Remaining part: "/siggw"
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Call score for the "/hc" URI pattern: 0.0
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Call score for the "/siggw" URI pattern: 1.0
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Selected route: "/siggw" -> org.apache.camel.component.restlet.MethodBasedRouter@790b3d68
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - 6 characters were matched
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - New base URI: "http://localhost:9000/siggw". No remaining part to match
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Delegating the call to the target Restlet
>> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ChallengeAuthenticator [] [] [] [] - Authentication succeeded. Valid credentials provided for identifier: siggw.user.
>> 02.12.2014 08:27:26.671 [Thread-2] DEBUG o.r.C.ChallengeAuthenticator [] [] [] [] - The authentication succeeded for the identifer "siggw.user" using the HTTP_Basic scheme.
>> 02.12.2014 08:27:26.671 [Thread-2] DEBUG c.i.s.s.a.r.r.JsonToMapMessageTransformer [] [] [] [] - Received request: {request1}
>> 02.12.2014 08:27:26.672 [Thread-2] INFO c.i.s.s.a.r.r.JsonToMapMessageTransformer [1] [testClient] [testClient@localhost] [998571731] - Message received: [message1]
>> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.r.CommonMessageValidator [1] [testClient] [testClient@localhost] [998571731] - Applying common validations
>> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.r.GetInfoRequestValidator [1] [testClient] [testClient@localhost] [998571731] - Executing GetInfoRequestValidator
>> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - GsmMap Producer called
>> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Message created
>> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Requests checked
>> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Requested infos prepared
>> 02.12.2014 08:27:26.673 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Sending request
>> 02.12.2014 08:27:26.674 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Request answered successfully
>> 02.12.2014 08:27:26.674 [Thread-2] DEBUG c.i.s.s.a.r.ResponseHandler [1] [testClient] [testClient@localhost] [998571731] - Response Handler called
>> 02.12.2014 08:27:26.674 [Thread-2] INFO c.i.s.s.a.r.ResponseHandler [1] [testClient] [testClient@localhost] [998571731] - Message returned: [message 1]
>> 02.12.2014 08:27:26.675 [Thread-2] DEBUG c.i.s.s.a.r.r.MapMessageToJsonTransformer [] [] [] [] - Returning response: {response1}
>> 02.12.2014 08:27:26.675 [Thread-2] INFO o.r.C.LogService [] [] [] [] - 2014-12-02 08:27:26 127.0.0.1 siggw.user - 9000 POST /siggw - 200 410 341 6 http://localhost:9000 Apache-HttpClient/4.2 (java 1.5) -
>>
>> TCP-Trace:
>> 86 2014-12-02 09:27:26.171193 127.0.0.1 127.0.0.1 HTTP 601 POST /siggw HTTP/1.1 (application/json)
>> 90 2014-12-02 09:27:26.677193 127.0.0.1 127.0.0.1 HTTP 450 HTTP/1.1 200 OK (application/json)
>>
>> Restlet component configuration:
>> <bean id="restlet" class="org.apache.camel.component.restlet.RestletComponent">
>> <property name="minThreads" value="50" />
>> <property name="maxThreads" value="50" />
>> <property name="lowThreads" value="50" />
>> <property name="maxQueued" value="-1" />
>> </bean>
>>
>> <util:map id="realm">
>> <entry key="siggw.user" value="${route.rest.password}" />
>> </util:map>
>>
>> Endpoint configuration:
>> this.siggwUri = "restlet:http://localhost:" + this.restPort + CommonConstantsA.RS_SIGGW_PATH + "?restletMethod=post&restletRealm=#realm";
>>
>> Java-Version:
>> java version "1.7.0_25"
>> Java(TM) SE Runtime Environment (build 1.7.0_25-b17)
>> Java HotSpot(TM) 64-Bit Server VM (build 23.25-b01, mixed mode)
>
>
>
> --
> Claus Ibsen
> -----------------
> Red Hat, Inc.
> Email: cibsen@redhat.com
> Twitter: davsclaus
> Blog: http://davsclaus.com
> Author of Camel in Action: http://www.manning.com/ibsen
> hawtio: http://hawt.io/
> fabric8: http://fabric8.io/
--
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen
hawtio: http://hawt.io/
fabric8: http://fabric8.io/
Re: Delayed request processing with Camel Restlet 2.14.0
Posted by Claus Ibsen <cl...@gmail.com>.
Hi
Try set synchronous=true on the restlet uris.
Also you can try downgraded restlet itself as we upgraded it too.
On Tue, Dec 2, 2014 at 10:57 AM, Thomas Günter
<Th...@intersys.ch> wrote:
> Hi,
>
> we moved a restful application based on the RESTLET component from Camel 2.13.3 to 2.14.0 and discovered severe perfomance problems with the latter version.
> Whereas requests with 2.13.3 were countinuously replied within a few (10) milliseconds, with 2.14.0 the requests took longer than 200ms (up to 500ms).
> The strange thing is, that the time passes by between the moment the request reaches the server and the moment the first log appears on server side.
>
> Has anyone experienced the same issue or an explanation/solution for this?
>
> Thanks in advance,
> Thomas
>
>
> Client side log:
> TEST 02.27.14 - 08:27:26.170 DEBUG c.i.c.h.c.f.FailoverLbHttpClient - Executing request [http://localhost:9000/siggw] to host [http://localhost:9000]
> TEST 02.27.14 - 08:27:26.677 DEBUG c.i.s.s.c.r.i.SigGwRsRequestExecutor - Received response from SIGGW [response]
>
> Server side log:
> 02.12.2014 08:27:26.669 [Thread-2] DEBUG o.r.C.LogService [] [] [] [] - Processing request to: "http://localhost:9000/siggw"
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Call score for the "org.restlet.routing.VirtualHost@7a3c388e" host: 1.0
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Default virtual host selected
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ServerRouter [] [] [] [] - Base URI: "http://localhost:9000". Remaining part: "/siggw"
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Call score for the "/hc" URI pattern: 0.0
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Call score for the "/siggw" URI pattern: 1.0
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Selected route: "/siggw" -> org.apache.camel.component.restlet.MethodBasedRouter@790b3d68
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - 6 characters were matched
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - New base URI: "http://localhost:9000/siggw". No remaining part to match
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.VirtualHost [] [] [] [] - Delegating the call to the target Restlet
> 02.12.2014 08:27:26.670 [Thread-2] DEBUG o.r.C.ChallengeAuthenticator [] [] [] [] - Authentication succeeded. Valid credentials provided for identifier: siggw.user.
> 02.12.2014 08:27:26.671 [Thread-2] DEBUG o.r.C.ChallengeAuthenticator [] [] [] [] - The authentication succeeded for the identifer "siggw.user" using the HTTP_Basic scheme.
> 02.12.2014 08:27:26.671 [Thread-2] DEBUG c.i.s.s.a.r.r.JsonToMapMessageTransformer [] [] [] [] - Received request: {request1}
> 02.12.2014 08:27:26.672 [Thread-2] INFO c.i.s.s.a.r.r.JsonToMapMessageTransformer [1] [testClient] [testClient@localhost] [998571731] - Message received: [message1]
> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.r.CommonMessageValidator [1] [testClient] [testClient@localhost] [998571731] - Applying common validations
> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.r.GetInfoRequestValidator [1] [testClient] [testClient@localhost] [998571731] - Executing GetInfoRequestValidator
> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - GsmMap Producer called
> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Message created
> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Requests checked
> 02.12.2014 08:27:26.672 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Requested infos prepared
> 02.12.2014 08:27:26.673 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Sending request
> 02.12.2014 08:27:26.674 [Thread-2] DEBUG c.i.s.s.a.c.g.GsmMapProducer [1] [testClient] [testClient@localhost] [998571731] - Request answered successfully
> 02.12.2014 08:27:26.674 [Thread-2] DEBUG c.i.s.s.a.r.ResponseHandler [1] [testClient] [testClient@localhost] [998571731] - Response Handler called
> 02.12.2014 08:27:26.674 [Thread-2] INFO c.i.s.s.a.r.ResponseHandler [1] [testClient] [testClient@localhost] [998571731] - Message returned: [message 1]
> 02.12.2014 08:27:26.675 [Thread-2] DEBUG c.i.s.s.a.r.r.MapMessageToJsonTransformer [] [] [] [] - Returning response: {response1}
> 02.12.2014 08:27:26.675 [Thread-2] INFO o.r.C.LogService [] [] [] [] - 2014-12-02 08:27:26 127.0.0.1 siggw.user - 9000 POST /siggw - 200 410 341 6 http://localhost:9000 Apache-HttpClient/4.2 (java 1.5) -
>
> TCP-Trace:
> 86 2014-12-02 09:27:26.171193 127.0.0.1 127.0.0.1 HTTP 601 POST /siggw HTTP/1.1 (application/json)
> 90 2014-12-02 09:27:26.677193 127.0.0.1 127.0.0.1 HTTP 450 HTTP/1.1 200 OK (application/json)
>
> Restlet component configuration:
> <bean id="restlet" class="org.apache.camel.component.restlet.RestletComponent">
> <property name="minThreads" value="50" />
> <property name="maxThreads" value="50" />
> <property name="lowThreads" value="50" />
> <property name="maxQueued" value="-1" />
> </bean>
>
> <util:map id="realm">
> <entry key="siggw.user" value="${route.rest.password}" />
> </util:map>
>
> Endpoint configuration:
> this.siggwUri = "restlet:http://localhost:" + this.restPort + CommonConstantsA.RS_SIGGW_PATH + "?restletMethod=post&restletRealm=#realm";
>
> Java-Version:
> java version "1.7.0_25"
> Java(TM) SE Runtime Environment (build 1.7.0_25-b17)
> Java HotSpot(TM) 64-Bit Server VM (build 23.25-b01, mixed mode)
--
Claus Ibsen
-----------------
Red Hat, Inc.
Email: cibsen@redhat.com
Twitter: davsclaus
Blog: http://davsclaus.com
Author of Camel in Action: http://www.manning.com/ibsen
hawtio: http://hawt.io/
fabric8: http://fabric8.io/