You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by Adel Boutros <ad...@live.com> on 2016/09/08 08:24:32 UTC
[Qpid Java Broker 6.0.x] Random failure in queue creation/deletion
using REST calls
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
RE: [Qpid Java Broker 6.0.x] Random failure in queue
creation/deletion using REST calls
Posted by Adel Boutros <ad...@live.com>.
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: adelboutros@live.com
> To: users@qpid.apache.org
> 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: adelboutros@live.com
> To: users@qpid.apache.org
> 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: orudyy@gmail.com
> > 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: users@qpid.apache.org
> >
> > 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 <ad...@live.com> 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: orudyy@gmail.com
> > >> 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: users@qpid.apache.org
> > >>
> > >> 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 <ad...@live.com> 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: users-unsubscribe@qpid.apache.org
> > >> For additional commands, e-mail: users-help@qpid.apache.org
> > >>
> > >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> > For additional commands, e-mail: users-help@qpid.apache.org
> >
>
RE: [Qpid Java Broker 6.0.x] Random failure in queue
creation/deletion using REST calls
Posted by Adel Boutros <ad...@live.com>.
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: adelboutros@live.com
To: users@qpid.apache.org
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: orudyy@gmail.com
> 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: users@qpid.apache.org
>
> 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 <ad...@live.com> 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: orudyy@gmail.com
> >> 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: users@qpid.apache.org
> >>
> >> 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 <ad...@live.com> 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: users-unsubscribe@qpid.apache.org
> >> For additional commands, e-mail: users-help@qpid.apache.org
> >>
> >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
>
RE: [Qpid Java Broker 6.0.x] Random failure in queue
creation/deletion using REST calls
Posted by Adel Boutros <ad...@live.com>.
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: orudyy@gmail.com
> 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: users@qpid.apache.org
>
> 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 <ad...@live.com> 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: orudyy@gmail.com
> >> 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: users@qpid.apache.org
> >>
> >> 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 <ad...@live.com> 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: users-unsubscribe@qpid.apache.org
> >> For additional commands, e-mail: users-help@qpid.apache.org
> >>
> >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
>
Re: [Qpid Java Broker 6.0.x] Random failure in queue
creation/deletion using REST calls
Posted by Oleksandr Rudyy <or...@gmail.com>.
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 <ad...@live.com> 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: orudyy@gmail.com
>> 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: users@qpid.apache.org
>>
>> 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 <ad...@live.com> 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: users-unsubscribe@qpid.apache.org
>> For additional commands, e-mail: users-help@qpid.apache.org
>>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
RE: [Qpid Java Broker 6.0.x] Random failure in queue
creation/deletion using REST calls
Posted by Adel Boutros <ad...@live.com>.
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: orudyy@gmail.com
> 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: users@qpid.apache.org
>
> 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 <ad...@live.com> 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: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
>
Re: [Qpid Java Broker 6.0.x] Random failure in queue
creation/deletion using REST calls
Posted by Oleksandr Rudyy <or...@gmail.com>.
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 <ad...@live.com> 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: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org