Hi Sergey. I've tried the Jersey Client (2.16) with the testcase - and it seems to work fine! No duplicate requests on the server side. Regards, Veit
Gesendet: Dienstag, 28. April 2015 um 13:07 Uhr Von: "Sergey Beryozkin" <[email protected]> An: [email protected] Betreff: Re: Aw: Re: Re: Re: Re: CXF JAX-RS client proxy and duplicate requests under load Hi Thanks for preparing this test, appears to be that using HttpClient resolves it. So I've updated pom.xml: <dependency> <groupId>org.apache.cxf</groupId> <artifactId>cxf-rt-transports-http-hc</artifactId> <version>3.0.4</version> <scope>test</scope> </dependency> and added this line to LoadTest(), immediately after creating a proxy, WebClient.getConfig(myService).getRequestContext().put("use.async.http.conduit", true); Run the test 3 times, works fine. I'm not sure what conclusions should be drawn here. I think it is probably Java HttpURLConnection sending some duplicate requests ? Can you please investigate if HttpURLConnection is known to do it in some cases ? I've no other ideas right now. May be also run a Jersey client in the same setup ? Sergey On 27/04/15 21:46, Veit Guna wrote: > Hi Sergey. > > I've created a separate standalone maven project, that demonstrates the > problem. > It's no beauty - but it gets to the point :). > > It contains a war that offers the endpoints and a cxf client, that sends > requests to it. > > If you run "mvn clean install" it will automatically deploy the war to a > tomcat > container via cargo and executes the TestNG testcase. And will hopefully fail > ;). > > As you requested a non-testng Test as well, try the "SimpleExecutor". It has a > main() you can execute. It should print Exceptions on the console that > indicates > the problem. You will see, that duplicate requests (UUIDs) will come to the > server. > Just search the logs on both sides for the duplicates and you'll see what I > mean. > > Funny thing: if I enable CXF logging, the tests are green :). Maybe has > something > TODO with timing. > > The war does not perform any authentication. It would be nice, If you could > try the "async transport" by yourself ;). > > Thanks > Veit > > > > Gesendet: Montag, 27. April 2015 um 18:43 Uhr > Von: "Sergey Beryozkin" <[email protected]> > An: [email protected] > Betreff: Re: Aw: Re: Re: Re: CXF JAX-RS client proxy and duplicate requests > under load > On 27/04/15 17:17, Veit Guna wrote: >> Thanks :). >> >> Sadly this doesn't make any difference :(. Still two requests... > This is sad indeed :-). > > Is there any chance for you to prepare a test (without TestNG, just a > java client with multiple threads) ? CXF proxy does not send the same > request twice for a given thread invocation. I honestly can not think of > why it might be the case. Hmm..., a couple of thoughts: > > - you use Basic Authentication, and CXF HttpConduit (wrapper above the > low-level HTTP transport) can retransmit if a server has replied with > 401. This is perhaps unlikely to cause a problem in your case but can > you please double check if the problem persists without using Basic Auth > (may be you need to temp disable the server-based authentication...) > > - Can you please include cxf-rt-transports-http-hc module which > HttpClient async transport. Then set a property with a bean, > "use.async.http.conduit" - true. And rerun the test. > > If you create a test that fails consistently then I can do the above > check with the async transport myself > > Thanks, Sergey > > >> >> Regards, >> Veit >> >> >> >> Gesendet: Montag, 27. April 2015 um 17:55 Uhr >> Von: "Sergey Beryozkin" <[email protected]> >> An: [email protected] >> Betreff: Re: Aw: Re: Re: CXF JAX-RS client proxy and duplicate requests >> under load >> Sure, use JAXRSClientFactoryBean instead, >> >> JAXRSClientFactoryBean bean = new JAXRSClientFactoryBean(); >> bean.setAddress(...); >> bean.setServiceClass(...); >> bean.setThreadSafe(true); >> bean.setUserName(...); >> bean.setPassword(...); >> SomeClass proxy = bean.create(SomeClass.class); >> >> Cheers, Sergey >> >> On 27/04/15 16:52, Veit Guna wrote: >>> Sure, but I can't find a suitable ctor on JAXRSClientFactory for >>> specifiying threadSafety AND username/password. >>> Could you give me a hint :)? >>> >>> Thanks. >>> >>> >>> >>> Gesendet: Montag, 27. April 2015 um 17:34 Uhr >>> Von: "Sergey Beryozkin" <[email protected]> >>> An: [email protected] >>> Betreff: Re: Aw: Re: CXF JAX-RS client proxy and duplicate requests under >>> load >>> Hi >>> Can you actually set a threadSafe flag on the factory before creating a >>> proxy ? >>> If you have a proxy reused by multiple threads and invoking multiple >>> methods on it there are likely to be some side-effects. >>> I'm not 100% yet that is the cause of the problem but I;d like you to >>> confirm that you are seeing the same problem even of you set a flag >>> >>> Thanks, Sergey >>> >>> On 27/04/15 16:31, Veit Guna wrote: >>>> Hi Sergey. >>>> >>>> I've tested some more. It seems that it is not only related to DELETE >>>> requests. >>>> I've isolated the problem into the following: >>>> >>>> - created an endpoint that simply takes an ID and stores it in a HashSet >>>> - if an entry already exists, it fails with an Exception (to demonstrate >>>> duplicate requests) >>>> - the endpoint always returns 404 >>>> - the test method (50 parallel threads, 50 invocations) >>>> - loops 10 times over: >>>> - performs a GET request to the endpoint using a newly generated uuid, >>>> within a try catch NotFoundException block. >>>> - performs a 2nd GET request using a new uuid, within a try catch >>>> NotFoundException block >>>> >>>> If all goes well, the test should be ok. >>>> But in my case, the same request (same UUID) came in 5 times and returned >>>> HTTP 500 (Exception due to duplicate UUIDs). >>>> >>>> That means, that if you have 2 invocations on a proxy, and the 2nd returns >>>> an Exception (e.g. NotFound) , it seems to send one of the requests again >>>> to the server. >>>> >>>> Can you confirm that behavior? >>>> >>>> Thanks >>>> Veit >>>> >>>> >>>> >>>> >>>> >>>> Gesendet: Montag, 27. April 2015 um 13:25 Uhr >>>> Von: "Sergey Beryozkin" <[email protected]> >>>> An: [email protected] >>>> Betreff: Re: CXF JAX-RS client proxy and duplicate requests under load >>>> Hi >>>> >>>> So even though the client proxy calls delete() only once you still see a >>>> DELETE request coming twice to the server. >>>> The initial question: Do you observe it for delete() only ? >>>> >>>> Thanks, Sergey >>>> >>>> >>>> >>>> On 27/04/15 11:28, Veit Guna wrote: >>>>> Hi. >>>>> >>>>> I'm using Apache CXF 3.0.4 in client JAX-RS proxy mode to access my >>>>> services on the server via annotated server interfaces. >>>>> Under normal operation, this works so far. >>>>> >>>>> Now, I've created a testcase that: >>>>> >>>>> - create a proxy with JAXRSClientFactory.create() >>>>> - creates 10 resources >>>>> - gets the 10 resources >>>>> - updates the 10 resources >>>>> - deletes the 10 resources. >>>>> >>>>> All above sequentially executed. Works when simply executed. >>>>> >>>>> Now I've configured TestNG to execute this test method with 50 threads >>>>> and 50 invocations concurrently. >>>>> Every now and then, it happens that the testcase fails with an HTTP 500 >>>>> error. >>>>> >>>>> I've checked the server logs and I can see, that a DELETE request for the >>>>> same resource comes in twice in >>>>> a distance of approx. 20 msecs. Of course, only one request succeeds, the >>>>> other fails. >>>>> >>>>> I've created logging on the testcase client side and I can confirm, that >>>>> delete() is only called once on >>>>> the CXF client proxy. So I'm wondering, why the client generates two >>>>> requests. Any idea what is happening there? >>>>> >>>>> I also enabled the CXF logging on client side via cxf.xml and I can see: >>>>> >>>>> - DELETE request is send (ID: 1779) >>>>> - Response HTTP 500 is returned (ID: 1779) >>>>> - DELETE request is send? (ID: 1779 - SAME id?! Logged as "Inbound >>>>> Message") >>>>> - No response. No further ID 1779. >>>>> >>>>> The server side logging looks like this >>>>> >>>>> - DELETE comes in (thread 437) >>>>> 20ms later >>>>> - DELETE comes in (thread 521) >>>>> 2secs later >>>>> - thread 521 completes successfully with HTTP 204. >>>>> - thread 437 throws HTTP 500. >>>>> >>>>> What I'm wondering is, how the order gets mixed up. Any idea how that can >>>>> happen? >>>>> >>>>> Here are detailed extractions from the logs: >>>>> >>>>> --cut here-- >>>>> ############ >>>>> Client side: >>>>> ############ >>>>> >>>>> 11:31:16,662 INFO [] [LoggingOutInterceptor:250] - Outbound Message >>>>> --------------------------- >>>>> ID: 1779 >>>>> Address: >>>>> http://localhost:8080/someservice/api/1/tenants/6a4322df-ad20-41b7-a5c9-908cadc509f5/repositories/f7c21bad-6743-4bed-916c-0b58d876204e/entries/46f069fa-c6a2-41cc-9dbc-ac5a2faffcfb >>>>> Http-Method: DELETE >>>>> Content-Type: application/xml >>>>> Headers: {Content-Type=[application/xml], Accept=[text/plain], >>>>> Authorization=[Basic ZmlsZW5zaGFyZTpzZWNyZXQ=]} >>>>> ... >>>>> ... >>>>> -------------------------------------- >>>>> 11:31:18,776 INFO [] [LoggingInInterceptor:250] - Inbound Message >>>>> ---------------------------- >>>>> ID: 1779 >>>>> Response-Code: 500 >>>>> Encoding: ISO-8859-1 >>>>> Content-Type: application/json >>>>> Headers: {connection=[close], Content-Length=[308], >>>>> content-type=[application/json], Date=[Mon, 27 Apr 2015 09:31:18 GMT], >>>>> Server=[Apache-Coyote/1.1]} >>>>> Payload: { >>>>> -------------------------------------- >>>>> 11:31:18,776 INFO [] [LoggingInInterceptor:250] - Inbound Message >>>>> ---------------------------- >>>>> ID: 1779 >>>>> Address: >>>>> http://localhost:8080/someservice/api/1/tenants/6a4322df-ad20-41b7-a5c9-908cadc509f5/repositories/f7c21bad-6743-4bed-916c-0b58d876204e/entries/46f069fa-c6a2-41cc-9dbc-ac5a2faffcfb >>>>> Http-Method: DELETE >>>>> Content-Type: application/xml >>>>> Headers: {Content-Type=[application/xml], Accept=[text/plain], >>>>> Authorization=[Basic ZmlsZW5zaGFyZTpzZWNyZXQ=]} >>>>> >>>>> >>>>> ############ >>>>> Server side: >>>>> ############ >>>>> >>>>> Apr 27, 2015 11:31:16 AM org.glassfish.jersey.filter.LoggingFilter log >>>>> INFO: 33572 * Server has received a request on thread >>>>> http-bio-8080-exec-437 >>>>> 33572 > DELETE >>>>> http://localhost:8080/someservice/api/1/tenants/6a4322df-ad20-41b7-a5c9-908cadc509f5/repositories/f7c21bad-6743-4bed-916c-0b58d876204e/entries/46f069fa-c6a2-41cc-9dbc-ac5a2faffcfb >>>>> 33572 > accept: text/plain >>>>> 33572 > authorization: Basic something= >>>>> 33572 > cache-control: no-cache >>>>> 33572 > connection: keep-alive >>>>> 33572 > content-type: */* >>>>> 33572 > host: localhost:8080 >>>>> 33572 > pragma: no-cache >>>>> 33572 > user-agent: Apache CXF 3.0.4 >>>>> >>>>> 20ms between them >>>>> >>>>> Apr 27, 2015 11:31:16 AM org.glassfish.jersey.filter.LoggingFilter log >>>>> INFO: 33573 * Server has received a request on thread >>>>> http-bio-8080-exec-521 >>>>> 33573 > DELETE >>>>> http://localhost:8080/someservice/api/1/tenants/6a4322df-ad20-41b7-a5c9-908cadc509f5/repositories/f7c21bad-6743-4bed-916c-0b58d876204e/entries/46f069fa-c6a2-41cc-9dbc-ac5a2faffcfb >>>>> 33573 > accept: text/plain >>>>> 33573 > authorization: Basic something= >>>>> 33573 > cache-control: no-cache >>>>> 33573 > connection: keep-alive >>>>> 33573 > content-type: */* >>>>> 33573 > host: localhost:8080 >>>>> 33573 > pragma: no-cache >>>>> 33573 > user-agent: Apache CXF 3.0.4 >>>>> >>>>> >>>>> Apr 27, 2015 11:31:18 AM org.glassfish.jersey.filter.LoggingFilter log >>>>> INFO: 33654 * Server responded with a response on thread >>>>> http-bio-8080-exec-521 >>>>> 33654 < 204 >>>>> >>>>> >>>>> Apr 27, 2015 11:31:18 AM org.glassfish.jersey.filter.LoggingFilter log >>>>> INFO: 33669 * Server responded with a response on thread >>>>> http-bio-8080-exec-437 >>>>> 33669 < 500 >>>>> 33669 < Content-Type: application/json >>>>> { >>>>> someerror json >>>>> } >>>>> --cut here-- >>>>> >>>>> Thanks. >>>>> Veit >>>>> >>>> >>>> >>> >>> >> >> >> -- >> Sergey Beryozkin >> >> Talend Community Coders >> http://coders.talend.com/ >> >> Blog: >> http://sberyozkin.blogspot.com[http://sberyozkin.blogspot.com][http://sberyozkin.blogspot.com[http://sberyozkin.blogspot.com]][http://sberyozkin.blogspot.com[http://sberyozkin.blogspot.com][http://sberyozkin.blogspot.com[http://sberyozkin.blogspot.com]]] >> > >
