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/07 08:12:30 UTC

[Java Broker - 6.0.4] Rest API logs are a bit tricky

Hello,

I was playing around with the Rest API and noticed the logs generated are not always easy to understand.
In my example, I tried to create twice the same queue expecting the second one to fail and it did. However when I tried to understand the logs generated, I found a lot of "successful tasks" and only one number indicating an error which is the response code 409.

My questions
* Is it expected for all the tasks to be successful especially the queue creation?
* Why is the queue being marked deleted and then created on the 2nd create request?
* Can't the log messages be clearer? (Example: Queue creation failed: Queue testQueue already exist)

I have set all of the below loggers to DEBUG on file logger:
org.eclipse.jetty.server.*
org.apache.qpid.server.management.plugin.session.*
org.apache.qpid.server.configuration.updater.*
org.apache.qpid.server.virtualhost.*
org.apache.qpid.server.queue.*
org.glassfish.jersey.filter.*

*****************
 Successful queue creation log
*****************
HttpManagement-HTTP-141 - /api/latest/queue/default/default] (o.e.j.s.Server) - REQUEST /api/latest/queue/default/default on AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=2,c=65},r=1
HttpManagement-HTTP-141 - /api/latest/queue/default/default] (o.e.j.s.h.ContextHandler) - scope null||/api/latest/queue/default/default @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-141 - /api/latest/queue/default/default] (o.e.j.s.h.ContextHandler) - context=||/api/latest/queue/default/default @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-141 - /api/latest/queue/default/default] (o.e.j.s.session) - Got Session ID ih390ue4aoki1nat59gm3p9jq from cookie
HttpManagement-HTTP-141 - /api/latest/queue/default/default] (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
HttpManagement-HTTP-141 - /api/latest/queue/default/default] (o.e.j.s.session) - session=org.eclipse.jetty.server.session.HashedSession:ih390ue4aoki1nat59gm3p9jq@30029392
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Performing Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77, name=default, type=DERBY]' with arguments 'childClass=Queue, name=testQueue2, type=null']
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Performing Task['create' on 'testQueue2']
2016-09-07 09:53:17,566 INFO  [VirtualHostNode-default-Config] (q.m.q.created) - [mng:ANONYMOUS(/client_ip:40826)] [vh(/default)/qu(testQueue2)] QUE-1001 : Create : ID: ec7d14c2-0f5d-4993-9e04-c18bad9e9daf Durable
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Task['create' on 'testQueue2'] performed successfully with result: null
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77, name=default, type=DERBY]' with arguments 'childClass=Queue, name=testQueue2, type=null'] performed successfully with result: null
HttpManagement-HTTP-141 - /api/latest/queue/default/default] (o.e.j.s.Server) - RESPONSE /api/latest/queue/default/default  201 handled=true
HttpManagement-HTTP-141] (o.e.j.s.AsyncHttpConnection) - Enabled read interest SCEP@7088e8{l(/client_ip:40831)<->r(/10.25.49.28:8080),s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@1bae008,g=HttpGenerator{s=4,h=0,b=-1,c=-1},p=HttpParser{s=0,l=2,c=65},r=1}
HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Disabled read interest while writing response SCEP@7088e8{l(/client_ip:40831)<->r(/10.25.49.28:8080),s=1,open=true,ishut=true,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=0,l=0,c=-3},r=1}
HttpManagement-HTTP-118 Selector2] (o.e.j.s.AbstractHttpConnection) - closed AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=0,l=0,c=-3},r=1
HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.Server) - REQUEST /service/structure on AsyncHttpConnection@8f0e18,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=7
HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.h.ContextHandler) - scope null||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.Server) - REQUEST /api/latest/broker on AsyncHttpConnection@1e668b7,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=7
HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.h.ContextHandler) - context=||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.h.ContextHandler) - scope null||/api/latest/broker @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.h.ContextHandler) - context=||/api/latest/broker @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) - session=org.eclipse.jetty.server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.session) - session=org.eclipse.jetty.server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.Server) - RESPONSE /service/structure  200 handled=true
HttpManagement-HTTP-141] (o.e.j.s.AsyncHttpConnection) - Enabled read interest SCEP@2a0faf{l(/client_ip:40824)<->r(/10.25.49.28:8080),s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@8f0e18,g=HttpGenerator{s=4,h=0,b=0,c=-1},p=HttpParser{s=0,l=42,c=0},r=7}
HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.Server) - RESPONSE /api/latest/broker  200 handled=true
HttpManagement-HTTP-137] (o.e.j.s.AsyncHttpConnection) - Enabled read interest SCEP@176e827{l(/client_ip:40825)<->r(/server_ip:8080),s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@1e668b7,g=HttpGenerator{s=4,h=0,b=0,c=-1},p=HttpParser{s=0,l=42,c=0},r=7}

*****************
Failed queue creation log 
*****************
HttpManagement-HTTP-136 - /api/latest/queue/default/default] (o.e.j.s.Server) - REQUEST /api/latest/queue/default/default on AsyncHttpConnection@172d263,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=2,l=2,c=65},r=1
HttpManagement-HTTP-136 - /api/latest/queue/default/default] (o.e.j.s.h.ContextHandler) - scope null||/api/latest/queue/default/default @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-136 - /api/latest/queue/default/default] (o.e.j.s.h.ContextHandler) - context=||/api/latest/queue/default/default @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-136 - /api/latest/queue/default/default] (o.e.j.s.session) - Got Session ID ih390ue4aoki1nat59gm3p9jq from cookie
HttpManagement-HTTP-136 - /api/latest/queue/default/default] (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
HttpManagement-HTTP-136 - /api/latest/queue/default/default] (o.e.j.s.session) - session=org.eclipse.jetty.server.session.HashedSession:ih390ue4aoki1nat59gm3p9jq@30029392
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Performing Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77, name=default, type=DERBY]' with arguments 'childClass=Queue, name=testQueue2, type=null']
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Performing Task['create' on 'testQueue2']
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Performing Task['set desired state' on 'testQueue2' with arguments 'DELETED']
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Task['set desired state' on 'testQueue2' with arguments 'DELETED'] performed successfully with result: null
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Task['create' on 'testQueue2'] performed successfully with result: null
VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) - Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77, name=default, type=DERBY]' with arguments 'childClass=Queue, name=testQueue2, type=null'] performed successfully with result: null
HttpManagement-HTTP-136 - /api/latest/queue/default/default] (o.e.j.s.Server) - RESPONSE /api/latest/queue/default/default  409 handled=true
HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Enabled read interest SCEP@1c9aa0b{l(/client_ip:40833)<->r(/server_ip:8080),s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@172d263,g=HttpGenerator{s=4,h=0,b=0,c=-1},p=HttpParser{s=0,l=2,c=65},r=1}
HttpManagement-HTTP-139] (o.e.j.s.AsyncHttpConnection) - Disabled read interest while writing response SCEP@1c9aa0b{l(/client_ip:40833)<->r(/server_ip:8080),s=1,open=true,ishut=true,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@172d263,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=0,l=0,c=-3},r=1}
HttpManagement-HTTP-119 Selector3] (o.e.j.s.AbstractHttpConnection) - closed AsyncHttpConnection@172d263,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=0,l=0,c=-3},r=1
HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.Server) - REQUEST /service/structure on AsyncHttpConnection@8f0e18,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=11
HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.h.ContextHandler) - scope null||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.Server) - REQUEST /api/latest/broker on AsyncHttpConnection@1e668b7,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=11
HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.h.ContextHandler) - context=||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.h.ContextHandler) - scope null||/api/latest/broker @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.h.ContextHandler) - context=||/api/latest/broker @ o.e.j.s.ServletContextHandler{/,null}
HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) - session=org.eclipse.jetty.server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.session) - session=org.eclipse.jetty.server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.Server) - RESPONSE /service/structure  200 handled=true
HttpManagement-HTTP-140] (o.e.j.s.AsyncHttpConnection) - Enabled read interest SCEP@2a0faf{l(/client_ip:40824)<->r(/server_ip:8080),s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@8f0e18,g=HttpGenerator{s=4,h=0,b=0,c=-1},p=HttpParser{s=0,l=42,c=0},r=11}
HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true] (o.e.j.s.Server) - RESPONSE /api/latest/broker  200 handled=true
HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Enabled read interest SCEP@176e827{l(/client_ip:40825)<->r(/server_ip:8080),s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@1e668b7,g=HttpGenerator{s=4,h=0,b=0,c=-1},p=HttpParser{s=0,l=42,c=0},r=11}


 		 	   		  

Re: [Java Broker - 6.0.4] Rest API logs are a bit tricky

Posted by Keith W <ke...@gmail.com>.
>> I agree that what we need is a clearer set of (INFO-level) log messages
>> which can be used to audit actions taken through the REST API that are
>> (potentially) mutating the broker state.  We'll raise a JIRA for this and
>> try to include something in the 6.2 release (I think we're a little late
>> for 6.1 now which we are trying to close down at the moment... 6.2 is
>> targeted to be released by the end of the year).

Raised as JIRA QPID-7419.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


RE: [Java Broker - 6.0.4] Rest API logs are a bit tricky

Posted by Adel Boutros <ad...@live.com>.
Hello Rob,

Indeed, this is helpful.

Just to share some context, I have some code which checks existence of a queue, deletes it and creates it via REST API in Java (javax.ws.rs-api). However, I have some random failures when I run the code repeatedly for a certain time. So, I wanted to see how I can check it from the logs of the broker

The logic is (each line involves a REST call):
If queue exits
     delete queue
create queue

Sometimes deletion fails and sometimes creation fails. I am still debugging it (I expect it to be a clumsy mistake in the code) but for example in the case of the creation failure, I have error 409 which could mean queue already exists but I don't think the error message is actually clear enough to confirm my assumption.

Regards,
Adel

> From: rob.j.godfrey@gmail.com
> Date: Wed, 7 Sep 2016 14:49:46 +0100
> Subject: Re: [Java Broker - 6.0.4] Rest API logs are a bit tricky
> To: users@qpid.apache.org
> 
> Hi Adel,
> 
> On 7 September 2016 at 09:12, Adel Boutros <ad...@live.com> wrote:
> 
> > Hello,
> >
> > I was playing around with the Rest API and noticed the logs generated are
> > not always easy to understand.
> > In my example, I tried to create twice the same queue expecting the second
> > one to fail and it did. However when I tried to understand the logs
> > generated, I found a lot of "successful tasks" and only one number
> > indicating an error which is the response code 409.
> >
> > My questions
> > * Is it expected for all the tasks to be successful especially the queue
> > creation?
> > * Why is the queue being marked deleted and then created on the 2nd create
> > request?
> >
> 
> So most of the logs you have turned on here are DEBUG logs which are really
> aimed at Qpid developers (or at least people who understand the underlying
> code) ... the fact that tasks are "successful" is just indicating that the
> task thread pool successfully completed a job without throwing an
> exception.  The fact that you see the state of the Queue being set to
> deleted in the second example is an artefact of how the underlying code
> works (the object is instantiated, then the duplication error is detected,
> then this new duplicate child needs to be deleted).  Logging at levels INFO
> and above should be understandable by end users.
> 
> 
> > * Can't the log messages be clearer? (Example: Queue creation failed:
> > Queue testQueue already exist)
> >
> 
> I agree that what we need is a clearer set of (INFO-level) log messages
> which can be used to audit actions taken through the REST API that are
> (potentially) mutating the broker state.  We'll raise a JIRA for this and
> try to include something in the 6.2 release (I think we're a little late
> for 6.1 now which we are trying to close down at the moment... 6.2 is
> targeted to be released by the end of the year).
> 
> Hope this helps,
> Rob
> 
> 
> >
> > I have set all of the below loggers to DEBUG on file logger:
> > org.eclipse.jetty.server.*
> > org.apache.qpid.server.management.plugin.session.*
> > org.apache.qpid.server.configuration.updater.*
> > org.apache.qpid.server.virtualhost.*
> > org.apache.qpid.server.queue.*
> > org.glassfish.jersey.filter.*
> >
> > *****************
> >  Successful queue creation log
> > *****************
> > HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> > (o.e.j.s.Server) - REQUEST /api/latest/queue/default/default on
> > AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=
> > -1},p=HttpParser{s=2,l=2,c=65},r=1
> > HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> > (o.e.j.s.h.ContextHandler) - scope null||/api/latest/queue/default/default
> > @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> > (o.e.j.s.h.ContextHandler) - context=||/api/latest/queue/default/default
> > @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> > (o.e.j.s.session) - Got Session ID ih390ue4aoki1nat59gm3p9jq from cookie
> > HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> > (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> > HashSessionManager@174c2d7
> > HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> > (o.e.j.s.session) - session=org.eclipse.jetty.
> > server.session.HashedSession:ih390ue4aoki1nat59gm3p9jq@30029392
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Performing Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> > name=default, type=DERBY]' with arguments 'childClass=Queue,
> > name=testQueue2, type=null']
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Performing Task['create' on 'testQueue2']
> > 2016-09-07 09:53:17,566 INFO  [VirtualHostNode-default-Config]
> > (q.m.q.created) - [mng:ANONYMOUS(/client_ip:40826)]
> > [vh(/default)/qu(testQueue2)] QUE-1001 : Create : ID:
> > ec7d14c2-0f5d-4993-9e04-c18bad9e9daf Durable
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Task['create' on 'testQueue2'] performed successfully with result: null
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> > name=default, type=DERBY]' with arguments 'childClass=Queue,
> > name=testQueue2, type=null'] performed successfully with result: null
> > HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> > (o.e.j.s.Server) - RESPONSE /api/latest/queue/default/default  201
> > handled=true
> > HttpManagement-HTTP-141] (o.e.j.s.AsyncHttpConnection) - Enabled read
> > interest SCEP@7088e8{l(/client_ip:40831)<->r(/10.25.49.28:8080),
> > s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> > AsyncHttpConnection@1bae008,g=HttpGenerator{s=4,h=0,b=-1,c=-
> > 1},p=HttpParser{s=0,l=2,c=65},r=1}
> > HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Disabled read
> > interest while writing response SCEP@7088e8{l(/client_ip:40831)<->r(/
> > 10.25.49.28:8080),s=1,open=true,ishut=true,oshut=false,rb=false,wb=false,
> > w=true,i=1r}-{AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=
> > -1},p=HttpParser{s=0,l=0,c=-3},r=1}
> > HttpManagement-HTTP-118 Selector2] (o.e.j.s.AbstractHttpConnection) -
> > closed AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=
> > -1},p=HttpParser{s=0,l=0,c=-3},r=1
> > HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.Server) - REQUEST
> > /service/structure on AsyncHttpConnection@8f0e18,g=
> > HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=7
> > HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.h.ContextHandler) -
> > scope null||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.Server) - REQUEST /api/latest/broker on AsyncHttpConnection@1e668b7
> > ,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=7
> > HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.h.ContextHandler) -
> > context=||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.h.ContextHandler) - scope null||/api/latest/broker @
> > o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) - Got
> > Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> > HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.h.ContextHandler) - context=||/api/latest/broker @
> > o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) -
> > sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
> > HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> > HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) -
> > session=org.eclipse.jetty.server.session.HashedSession:
> > 1plelsp7va5x1137kd16hhau2b@24899107
> > HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> > HashSessionManager@174c2d7
> > HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.session) - session=org.eclipse.jetty.
> > server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
> > HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.Server) - RESPONSE
> > /service/structure  200 handled=true
> > HttpManagement-HTTP-141] (o.e.j.s.AsyncHttpConnection) - Enabled read
> > interest SCEP@2a0faf{l(/client_ip:40824)<->r(/10.25.49.28:8080),
> > s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> > AsyncHttpConnection@8f0e18,g=HttpGenerator{s=4,h=0,b=0,c=-
> > 1},p=HttpParser{s=0,l=42,c=0},r=7}
> > HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.Server) - RESPONSE /api/latest/broker  200 handled=true
> > HttpManagement-HTTP-137] (o.e.j.s.AsyncHttpConnection) - Enabled read
> > interest SCEP@176e827{l(/client_ip:40825)<->r(/server_ip:8080),s=
> > 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> > AsyncHttpConnection@1e668b7,g=HttpGenerator{s=4,h=0,b=0,c=-
> > 1},p=HttpParser{s=0,l=42,c=0},r=7}
> >
> > *****************
> > Failed queue creation log
> > *****************
> > HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> > (o.e.j.s.Server) - REQUEST /api/latest/queue/default/default on
> > AsyncHttpConnection@172d263,g=HttpGenerator{s=0,h=-1,b=-1,c=
> > -1},p=HttpParser{s=2,l=2,c=65},r=1
> > HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> > (o.e.j.s.h.ContextHandler) - scope null||/api/latest/queue/default/default
> > @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> > (o.e.j.s.h.ContextHandler) - context=||/api/latest/queue/default/default
> > @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> > (o.e.j.s.session) - Got Session ID ih390ue4aoki1nat59gm3p9jq from cookie
> > HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> > (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> > HashSessionManager@174c2d7
> > HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> > (o.e.j.s.session) - session=org.eclipse.jetty.
> > server.session.HashedSession:ih390ue4aoki1nat59gm3p9jq@30029392
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Performing Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> > name=default, type=DERBY]' with arguments 'childClass=Queue,
> > name=testQueue2, type=null']
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Performing Task['create' on 'testQueue2']
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Performing Task['set desired state' on 'testQueue2' with arguments
> > 'DELETED']
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Task['set desired state' on 'testQueue2' with arguments 'DELETED']
> > performed successfully with result: null
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Task['create' on 'testQueue2'] performed successfully with result: null
> > VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> > Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> > name=default, type=DERBY]' with arguments 'childClass=Queue,
> > name=testQueue2, type=null'] performed successfully with result: null
> > HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> > (o.e.j.s.Server) - RESPONSE /api/latest/queue/default/default  409
> > handled=true
> > HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Enabled read
> > interest SCEP@1c9aa0b{l(/client_ip:40833)<->r(/server_ip:8080),s=
> > 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> > AsyncHttpConnection@172d263,g=HttpGenerator{s=4,h=0,b=0,c=-
> > 1},p=HttpParser{s=0,l=2,c=65},r=1}
> > HttpManagement-HTTP-139] (o.e.j.s.AsyncHttpConnection) - Disabled read
> > interest while writing response SCEP@1c9aa0b{l(/client_ip:
> > 40833)<->r(/server_ip:8080),s=1,open=true,ishut=true,oshut=
> > false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@172d263,g=
> > HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=0,l=0,c=-3},r=1}
> > HttpManagement-HTTP-119 Selector3] (o.e.j.s.AbstractHttpConnection) -
> > closed AsyncHttpConnection@172d263,g=HttpGenerator{s=0,h=-1,b=-1,c=
> > -1},p=HttpParser{s=0,l=0,c=-3},r=1
> > HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.Server) - REQUEST
> > /service/structure on AsyncHttpConnection@8f0e18,g=
> > HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=11
> > HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.h.ContextHandler) -
> > scope null||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.Server) - REQUEST /api/latest/broker on AsyncHttpConnection@1e668b7
> > ,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=11
> > HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.h.ContextHandler) -
> > context=||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.h.ContextHandler) - scope null||/api/latest/broker @
> > o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) - Got
> > Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> > HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.h.ContextHandler) - context=||/api/latest/broker @
> > o.e.j.s.ServletContextHandler{/,null}
> > HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) -
> > sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
> > HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> > HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) -
> > session=org.eclipse.jetty.server.session.HashedSession:
> > 1plelsp7va5x1137kd16hhau2b@24899107
> > HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> > HashSessionManager@174c2d7
> > HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.session) - session=org.eclipse.jetty.
> > server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
> > HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.Server) - RESPONSE
> > /service/structure  200 handled=true
> > HttpManagement-HTTP-140] (o.e.j.s.AsyncHttpConnection) - Enabled read
> > interest SCEP@2a0faf{l(/client_ip:40824)<->r(/server_ip:8080),s=
> > 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> > AsyncHttpConnection@8f0e18,g=HttpGenerator{s=4,h=0,b=0,c=-
> > 1},p=HttpParser{s=0,l=42,c=0},r=11}
> > HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> > (o.e.j.s.Server) - RESPONSE /api/latest/broker  200 handled=true
> > HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Enabled read
> > interest SCEP@176e827{l(/client_ip:40825)<->r(/server_ip:8080),s=
> > 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> > AsyncHttpConnection@1e668b7,g=HttpGenerator{s=4,h=0,b=0,c=-
> > 1},p=HttpParser{s=0,l=42,c=0},r=11}
> >
> >
> >
 		 	   		  

Re: [Java Broker - 6.0.4] Rest API logs are a bit tricky

Posted by Rob Godfrey <ro...@gmail.com>.
Hi Adel,

On 7 September 2016 at 09:12, Adel Boutros <ad...@live.com> wrote:

> Hello,
>
> I was playing around with the Rest API and noticed the logs generated are
> not always easy to understand.
> In my example, I tried to create twice the same queue expecting the second
> one to fail and it did. However when I tried to understand the logs
> generated, I found a lot of "successful tasks" and only one number
> indicating an error which is the response code 409.
>
> My questions
> * Is it expected for all the tasks to be successful especially the queue
> creation?
> * Why is the queue being marked deleted and then created on the 2nd create
> request?
>

So most of the logs you have turned on here are DEBUG logs which are really
aimed at Qpid developers (or at least people who understand the underlying
code) ... the fact that tasks are "successful" is just indicating that the
task thread pool successfully completed a job without throwing an
exception.  The fact that you see the state of the Queue being set to
deleted in the second example is an artefact of how the underlying code
works (the object is instantiated, then the duplication error is detected,
then this new duplicate child needs to be deleted).  Logging at levels INFO
and above should be understandable by end users.


> * Can't the log messages be clearer? (Example: Queue creation failed:
> Queue testQueue already exist)
>

I agree that what we need is a clearer set of (INFO-level) log messages
which can be used to audit actions taken through the REST API that are
(potentially) mutating the broker state.  We'll raise a JIRA for this and
try to include something in the 6.2 release (I think we're a little late
for 6.1 now which we are trying to close down at the moment... 6.2 is
targeted to be released by the end of the year).

Hope this helps,
Rob


>
> I have set all of the below loggers to DEBUG on file logger:
> org.eclipse.jetty.server.*
> org.apache.qpid.server.management.plugin.session.*
> org.apache.qpid.server.configuration.updater.*
> org.apache.qpid.server.virtualhost.*
> org.apache.qpid.server.queue.*
> org.glassfish.jersey.filter.*
>
> *****************
>  Successful queue creation log
> *****************
> HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> (o.e.j.s.Server) - REQUEST /api/latest/queue/default/default on
> AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=
> -1},p=HttpParser{s=2,l=2,c=65},r=1
> HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> (o.e.j.s.h.ContextHandler) - scope null||/api/latest/queue/default/default
> @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> (o.e.j.s.h.ContextHandler) - context=||/api/latest/queue/default/default
> @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> (o.e.j.s.session) - Got Session ID ih390ue4aoki1nat59gm3p9jq from cookie
> HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> HashSessionManager@174c2d7
> HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> (o.e.j.s.session) - session=org.eclipse.jetty.
> server.session.HashedSession:ih390ue4aoki1nat59gm3p9jq@30029392
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Performing Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> name=default, type=DERBY]' with arguments 'childClass=Queue,
> name=testQueue2, type=null']
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Performing Task['create' on 'testQueue2']
> 2016-09-07 09:53:17,566 INFO  [VirtualHostNode-default-Config]
> (q.m.q.created) - [mng:ANONYMOUS(/client_ip:40826)]
> [vh(/default)/qu(testQueue2)] QUE-1001 : Create : ID:
> ec7d14c2-0f5d-4993-9e04-c18bad9e9daf Durable
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Task['create' on 'testQueue2'] performed successfully with result: null
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> name=default, type=DERBY]' with arguments 'childClass=Queue,
> name=testQueue2, type=null'] performed successfully with result: null
> HttpManagement-HTTP-141 - /api/latest/queue/default/default]
> (o.e.j.s.Server) - RESPONSE /api/latest/queue/default/default  201
> handled=true
> HttpManagement-HTTP-141] (o.e.j.s.AsyncHttpConnection) - Enabled read
> interest SCEP@7088e8{l(/client_ip:40831)<->r(/10.25.49.28:8080),
> s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> AsyncHttpConnection@1bae008,g=HttpGenerator{s=4,h=0,b=-1,c=-
> 1},p=HttpParser{s=0,l=2,c=65},r=1}
> HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Disabled read
> interest while writing response SCEP@7088e8{l(/client_ip:40831)<->r(/
> 10.25.49.28:8080),s=1,open=true,ishut=true,oshut=false,rb=false,wb=false,
> w=true,i=1r}-{AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=
> -1},p=HttpParser{s=0,l=0,c=-3},r=1}
> HttpManagement-HTTP-118 Selector2] (o.e.j.s.AbstractHttpConnection) -
> closed AsyncHttpConnection@1bae008,g=HttpGenerator{s=0,h=-1,b=-1,c=
> -1},p=HttpParser{s=0,l=0,c=-3},r=1
> HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.Server) - REQUEST
> /service/structure on AsyncHttpConnection@8f0e18,g=
> HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=7
> HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.h.ContextHandler) -
> scope null||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.Server) - REQUEST /api/latest/broker on AsyncHttpConnection@1e668b7
> ,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=7
> HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.h.ContextHandler) -
> context=||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.h.ContextHandler) - scope null||/api/latest/broker @
> o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) - Got
> Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.h.ContextHandler) - context=||/api/latest/broker @
> o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) -
> sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
> HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.session) -
> session=org.eclipse.jetty.server.session.HashedSession:
> 1plelsp7va5x1137kd16hhau2b@24899107
> HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> HashSessionManager@174c2d7
> HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.session) - session=org.eclipse.jetty.
> server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
> HttpManagement-HTTP-141 - /service/structure] (o.e.j.s.Server) - RESPONSE
> /service/structure  200 handled=true
> HttpManagement-HTTP-141] (o.e.j.s.AsyncHttpConnection) - Enabled read
> interest SCEP@2a0faf{l(/client_ip:40824)<->r(/10.25.49.28:8080),
> s=1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> AsyncHttpConnection@8f0e18,g=HttpGenerator{s=4,h=0,b=0,c=-
> 1},p=HttpParser{s=0,l=42,c=0},r=7}
> HttpManagement-HTTP-137 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.Server) - RESPONSE /api/latest/broker  200 handled=true
> HttpManagement-HTTP-137] (o.e.j.s.AsyncHttpConnection) - Enabled read
> interest SCEP@176e827{l(/client_ip:40825)<->r(/server_ip:8080),s=
> 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> AsyncHttpConnection@1e668b7,g=HttpGenerator{s=4,h=0,b=0,c=-
> 1},p=HttpParser{s=0,l=42,c=0},r=7}
>
> *****************
> Failed queue creation log
> *****************
> HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> (o.e.j.s.Server) - REQUEST /api/latest/queue/default/default on
> AsyncHttpConnection@172d263,g=HttpGenerator{s=0,h=-1,b=-1,c=
> -1},p=HttpParser{s=2,l=2,c=65},r=1
> HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> (o.e.j.s.h.ContextHandler) - scope null||/api/latest/queue/default/default
> @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> (o.e.j.s.h.ContextHandler) - context=||/api/latest/queue/default/default
> @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> (o.e.j.s.session) - Got Session ID ih390ue4aoki1nat59gm3p9jq from cookie
> HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> HashSessionManager@174c2d7
> HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> (o.e.j.s.session) - session=org.eclipse.jetty.
> server.session.HashedSession:ih390ue4aoki1nat59gm3p9jq@30029392
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Performing Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> name=default, type=DERBY]' with arguments 'childClass=Queue,
> name=testQueue2, type=null']
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Performing Task['create' on 'testQueue2']
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Performing Task['set desired state' on 'testQueue2' with arguments
> 'DELETED']
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Task['set desired state' on 'testQueue2' with arguments 'DELETED']
> performed successfully with result: null
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Task['create' on 'testQueue2'] performed successfully with result: null
> VirtualHostNode-default-Config] (o.a.q.s.c.u.TaskExecutorImpl) -
> Task['create child' on 'VirtualHost[id=36df8647-0bd1-494e-814b-4268803c5d77,
> name=default, type=DERBY]' with arguments 'childClass=Queue,
> name=testQueue2, type=null'] performed successfully with result: null
> HttpManagement-HTTP-136 - /api/latest/queue/default/default]
> (o.e.j.s.Server) - RESPONSE /api/latest/queue/default/default  409
> handled=true
> HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Enabled read
> interest SCEP@1c9aa0b{l(/client_ip:40833)<->r(/server_ip:8080),s=
> 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> AsyncHttpConnection@172d263,g=HttpGenerator{s=4,h=0,b=0,c=-
> 1},p=HttpParser{s=0,l=2,c=65},r=1}
> HttpManagement-HTTP-139] (o.e.j.s.AsyncHttpConnection) - Disabled read
> interest while writing response SCEP@1c9aa0b{l(/client_ip:
> 40833)<->r(/server_ip:8080),s=1,open=true,ishut=true,oshut=
> false,rb=false,wb=false,w=true,i=1r}-{AsyncHttpConnection@172d263,g=
> HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=0,l=0,c=-3},r=1}
> HttpManagement-HTTP-119 Selector3] (o.e.j.s.AbstractHttpConnection) -
> closed AsyncHttpConnection@172d263,g=HttpGenerator{s=0,h=-1,b=-1,c=
> -1},p=HttpParser{s=0,l=0,c=-3},r=1
> HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.Server) - REQUEST
> /service/structure on AsyncHttpConnection@8f0e18,g=
> HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=11
> HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.h.ContextHandler) -
> scope null||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.Server) - REQUEST /api/latest/broker on AsyncHttpConnection@1e668b7
> ,g=HttpGenerator{s=0,h=-1,b=-1,c=-1},p=HttpParser{s=-5,l=42,c=0},r=11
> HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.h.ContextHandler) -
> context=||/service/structure @ o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.h.ContextHandler) - scope null||/api/latest/broker @
> o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) - Got
> Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.h.ContextHandler) - context=||/api/latest/broker @
> o.e.j.s.ServletContextHandler{/,null}
> HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) -
> sessionManager=org.eclipse.jetty.server.session.HashSessionManager@174c2d7
> HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.session) - Got Session ID 1plelsp7va5x1137kd16hhau2b from cookie
> HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.session) -
> session=org.eclipse.jetty.server.session.HashedSession:
> 1plelsp7va5x1137kd16hhau2b@24899107
> HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.session) - sessionManager=org.eclipse.jetty.server.session.
> HashSessionManager@174c2d7
> HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.session) - session=org.eclipse.jetty.
> server.session.HashedSession:1plelsp7va5x1137kd16hhau2b@24899107
> HttpManagement-HTTP-140 - /service/structure] (o.e.j.s.Server) - RESPONSE
> /service/structure  200 handled=true
> HttpManagement-HTTP-140] (o.e.j.s.AsyncHttpConnection) - Enabled read
> interest SCEP@2a0faf{l(/client_ip:40824)<->r(/server_ip:8080),s=
> 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> AsyncHttpConnection@8f0e18,g=HttpGenerator{s=4,h=0,b=0,c=-
> 1},p=HttpParser{s=0,l=42,c=0},r=11}
> HttpManagement-HTTP-136 - /api/latest/broker?depth=2&excludeInheritedContext=true]
> (o.e.j.s.Server) - RESPONSE /api/latest/broker  200 handled=true
> HttpManagement-HTTP-136] (o.e.j.s.AsyncHttpConnection) - Enabled read
> interest SCEP@176e827{l(/client_ip:40825)<->r(/server_ip:8080),s=
> 1,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=1r}-{
> AsyncHttpConnection@1e668b7,g=HttpGenerator{s=4,h=0,b=0,c=-
> 1},p=HttpParser{s=0,l=42,c=0},r=11}
>
>
>