Hi Sergey. Thanks for looking into this! Meanwhile I tried your suggested code with creating a new bus and shutting it down when the application is stopped. This seems to work for me. The thread pool is closed appropiately then. But I'm still looking forward for the fix of the "normal" client ;). It's always a good think to have a less threads as possible around... Thanks! Veit
Gesendet: Donnerstag, 30. April 2015 um 12:42 Uhr Von: "Sergey Beryozkin" <[email protected]> An: [email protected] Betreff: Re: Aw: Re: Re: Re: Re: Re: CXF JAX-RS client proxy and duplicate requests under load Hi Veit Thanks, it may well be pointing to the fact CXF Http Transport (HttpConduit) is setting some properties on HttpUrlConnection that is affecting it. I'll have to investigate - unlikely though to get any result in time for the release. Please consider using the HttpClient conduit for now (as I said I can try make the the client bus.shutdown be called automatically if it helps in clearing HttpClient pool of threads). Thanks Sergey On 30/04/15 11:36, Veit Guna wrote: > 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]]][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]]]] >>> >> >> > >
