Finally, I was able to test client-side using spring RestTemplate and I was able to execute the code 10 000 without any issues.
I will replace Jersey client with RestTemplate in my code. Thank you for your valuable help Alex. Regards, Adel > From: [email protected] > To: [email protected] > Subject: RE: [Qpid Java Broker 6.0.x] Random failure in queue > creation/deletion using REST calls > Date: Fri, 9 Sep 2016 15:39:03 +0200 > > Hello Alex, > > Actually, I launched Wireshark and it seems you are right, 2 delete requests > are sent consecutively. > The problem seems to be in fact coming from Jersey Client > > Wireshark (filter: http) > > 47992 30.115608 src.ip 33273 dest.ip 8080 112 HTTP > PUT /api/latest/queue/default/default HTTP/1.1 (application/json) > 48386 30.127898 dest.ip 8080 src.ip 33273 317 HTTP > HTTP/1.1 201 Created > 48430 30.128921 src.ip 33142 dest.ip 8080 291 HTTP > GET /api/latest/queue/default/default/restQueueFail HTTP/1.1 > 48904 30.142792 src.ip 33106 dest.ip 8080 294 HTTP > DELETE /api/latest/queue/default/default/restQueueFail HTTP/1.1 > 48908 30.142955 dest.ip 8080 src.ip 33142 323 HTTP > HTTP/1.1 200 OK (application/json) > 49592 30.161594 src.ip 33274 dest.ip 8080 294 HTTP > DELETE /api/latest/queue/default/default/restQueueFail HTTP/1.1 > 49700 30.171616 dest.ip 8080 src.ip 33106 237 HTTP > HTTP/1.1 200 OK > 49718 30.193521 dest.ip 8080 src.ip 33274 283 HTTP > HTTP/1.1 404 Not Found (application/json) > > Regards, > Adel > From: [email protected] > To: [email protected] > Subject: RE: [Qpid Java Broker 6.0.x] Random failure in queue > creation/deletion using REST calls > Date: Fri, 9 Sep 2016 15:19:09 +0200 > > > > > Hello Alex, > > I did some debugging and activated logging on Qpid Broker Side and Jersey > Client Side. Analyzing the logs, I don't see any wrong behavior client-side > because I don't see double request. > On the contrary, I see a delete request and then a create request which is > failing. > However, on the broker side, I see 2 requests being received in parallel. I > think this is where the problem lies. > > I stopped logging at the moment a query failed. > > ======== > Broker Logs > ======== > [HttpManagement-HTTP-378] (o.e.j.s.Server) - REQUEST > /api/latest/queue/default/default on > AsyncHttpConnection@7b1b3aa2,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=2,c=58},r=5 > [HttpManagement-HTTP-373] (o.e.j.s.Server) - REQUEST > /api/latest/queue/default/default on > AsyncHttpConnection@66381a52,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=2,c=58},r=1 > [HttpManagement-HTTP-378] (o.e.j.s.Server) - RESPONSE > /api/latest/queue/default/default 201 handled=true > [HttpManagement-HTTP-373] (o.e.j.s.Server) - RESPONSE > /api/latest/queue/default/default 409 handled=true > > ========== > Jersey Client logs > ========== > <record> > <date>2016-09-09T15:13:26</date> > <millis>1473426806227</millis> > <sequence>4390</sequence> > <logger>org.glassfish.jersey.logging.LoggingFeature</logger> > <level>INFO</level> > <class>org.glassfish.jersey.logging.LoggingInterceptor</class> > <method>log</method> > <thread>1</thread> > <message>2196 * Sending client request on thread main > 2196 > DELETE > http://localhost:8080/api/latest/queue/default/default/restQueueFail > 2196 > Accept: application/json > 2196 > Authorization: Basic Z3Vlc3Q6Z3Vlc3Q= > </message> > </record> > <record> > <date>2016-09-09T15:13:26</date> > <millis>1473426806227</millis> > <sequence>4391</sequence> > <logger>org.glassfish.jersey.logging.LoggingFeature</logger> > <level>INFO</level> > <class>org.glassfish.jersey.logging.LoggingInterceptor</class> > <method>log</method> > <thread>1</thread> > <message>2196 * Client response received on thread main > 2196 < 200 > 2196 < Cache-Control: no-cache > 2196 < Content-Length: 0 > 2196 < Expires: Thu, 01 Jan 1970 00:00:00 GMT > 2196 < Pragma: no-cache > 2196 < Set-Cookie: JSESSIONID_8080=1xc1j94fhqpz8dznsnugibzka;Path=/ > </message> > </record> > <record> > <date>2016-09-09T15:13:26</date> > <millis>1473426806227</millis> > <sequence>4392</sequence> > <logger>org.glassfish.jersey.logging.LoggingFeature</logger> > <level>INFO</level> > <class>org.glassfish.jersey.logging.LoggingInterceptor</class> > <method>log</method> > <thread>1</thread> > <message>2197 * Sending client request on thread main > 2197 > PUT http://localhost:8080/api/latest/queue/default/default > 2197 > Accept: application/json > 2197 > Authorization: Basic Z3Vlc3Q6Z3Vlc3Q= > 2197 > Content-Type: application/json > </message> > </record> > <record> > <date>2016-09-09T15:13:26</date> > <millis>1473426806243</millis> > <sequence>4393</sequence> > <logger>org.glassfish.jersey.logging.LoggingFeature</logger> > <level>INFO</level> > <class>org.glassfish.jersey.logging.LoggingInterceptor</class> > <method>log</method> > <thread>1</thread> > <message>2197 * Client response received on thread main > 2197 < 409 > 2197 < Content-Length: 73 > 2197 < Content-Type: application/json;charset=UTF-8 > 2197 < Expires: Thu, 01 Jan 1970 00:00:00 GMT > 2197 < Set-Cookie: JSESSIONID_8080=1ccjr3yiqac6l1slkizfbasepa;Path=/ > </message> > </record> > > > From: [email protected] > > Date: Fri, 9 Sep 2016 14:01:23 +0100 > > Subject: Re: [Qpid Java Broker 6.0.x] Random failure in queue > > creation/deletion using REST calls > > To: [email protected] > > > > Adel, > > I simply changed the log level to ALL for logging rule Qpid > > (org.apache.qpid.*) in logfile logger. That enables all possible Qpid > > logging. > > Alternately, you can just add new logging rule to enable debug logging > > for logger "org.apache.qpid.server.management.plugin.filter.LoggingFilter". > > > > Potentially http request/response logging can be filtered from broker > > logs (with ALL logging enabled) using egrep utility, for example: > > tail -f ~/.qpid/log/qpid.log | egrep "REQUEST|RESPONSE" > > > > Kind Regards, > > Alex > > > > > > > > On 9 September 2016 at 13:01, Adel Boutros <[email protected]> wrote: > > > Hello Alex, > > > I am glad you were able to reproduce. > > > Can you please share what you activate in the logging to see the > > > duplicate request? > > > Regards,Adel > > > > > >> From: [email protected] > > >> Date: Fri, 9 Sep 2016 12:22:09 +0100 > > >> Subject: Re: [Qpid Java Broker 6.0.x] Random failure in queue > > >> creation/deletion using REST calls > > >> To: [email protected] > > >> > > >> Hi Adel, > > >> I looked into an issue you had reported. I ran your sample application > > >> attached to the JIRA QPID-7420 and found that every time when > > >> application fails it sends 2 similar requests: first one is handled by > > >> the broker successfully and the other one fails because the work is > > >> already performed as part of first request. For example, if first > > >> request deletes the queue, the second one receives 404, as queue does > > >> not exist anymore. > > >> > > >> Unfortunately it was tricky to discover that two same requests are > > >> made from the application, as Broker operational logging does not log > > >> failed management operation attempts. It seems we need to improve > > >> logging in this area. I had to switch to DEBUG logging in order to > > >> find the cause of the problem. > > >> > > >> I am not familiar with jersey and not sure why 2 requests are sent. It > > >> could be an issue with jersey itself or some settings... > > >> > > >> I am going to resolve QPID-7420 as not an issue. > > >> > > >> Kind Regards, > > >> Alex > > >> > > >> On 8 September 2016 at 09:24, Adel Boutros <[email protected]> wrote: > > >> > Hello guys, > > >> > > > >> > As I mentioned in my previous post, I am having some random REST call > > >> > failures when deleting and creating a queue. I was able to have a > > >> > smaller test code but still the error is very random. I launch my test > > >> > code 10 000 times to get the exception: The failure occurs sometimes > > >> > at run 600 or run 2000, etc... > > >> > > > >> > I don't know if someone has faced a similar issue before. > > >> > > > >> > I have also created a Jira issue for this with the minimalist test > > >> > code I could find so far: > > >> > https://issues.apache.org/jira/browse/QPID-7420 > > >> > > > >> > Do not hesitate to let me know if there are missing information. > > >> > > > >> > I have tested with Java Broker 6.0.0, 6.0.1 and 6.0.4 and they all > > >> > have the issue. > > >> > > > >> > I would like to keep debugging the issue from my side. So I was > > >> > wondering if you could provide me some hints where to look in the code > > >> > or what to activate to see in the logs if possible? > > >> > > > >> > Regards, > > >> > Adel > > >> > > > >> > > >> --------------------------------------------------------------------- > > >> To unsubscribe, e-mail: [email protected] > > >> For additional commands, e-mail: [email protected] > > >> > > > > > > > --------------------------------------------------------------------- > > To unsubscribe, e-mail: [email protected] > > For additional commands, e-mail: [email protected] > > > >
