Following on from the high level design, this page will provide a more detailed design approach to implement status update logging in the Java broker.
The logging hierarchy identified is not suitable to be directly used by Log4j as there is multiple routes and loops in the graph.
To better address this and to allow us to more eaily move between logging implementations an abstraction is recommended. This approach will allow the simplification of the logic around determining if logging should be performed in the main code base. For example a Binding logging statement can be controlled via Exchange and Queue, each of which may be limited to s specific instance.
This design will cover the following areas:
At this stage configuration will be limited to the addtion to the main config.xml file of the following option:
<broker> ... <logging> <level>INFO</level> <logging> </broker> |
This INFO level setting will be the default value if the section is not included in the configuration file. The setting will be global for all virtualhosts and will be exposed via the management console as logger 'qpid.operational' to allow dynamic level setting.
The ability to configure more fine grained logging will be investigated here, but will not be implemented in the initial phase.
The following six levels represent the range of levels that will be available as part of the logging configuration. Whilst the initial implementation may not include specific messages at each level this section simply describes the type of message that would appear at each level and the behaviour associated with logging at that level. The levels are listed in order of the frequency of logging events. In addition to these six levels the values ALL and OFF may be used, these respectively represent TRACE and FATAL. FATAL messages will always be logged as they are associated with a broker shutdown.
FATAL
Occurs when an unrecoverable error has occured. A stack trace is automatically generated and a System.exit(1) is called halting the process.
e.g. Data corruption
ERROR
Occurs when a problem occurs in the system but it can generally continue to operate.
e.g. Unexpected error occurs that is limited to a single connection, i.e. not message store related.
WARN
Occurs when a potententialy harmful situation occurs.
e.g. Unexpected connection closure
INFO
General operational logging level, no logging on message delivery path way. No performance impact. Recommended for production use.
e.g. Creation/Destruction events
DEBUG
Additional logging on message delivery path way. May have performance impact. Not recommended for long term production use
e.g. Message Enqueue/Dequeue
TRACE
Full delivery path debugging. Will have performance impact. Not intended for production use.
e.g. Message selector behaviour
The abstraction layer allows us to fully decouple the logging mechanism from any operational logging that the broker may wish to perform. The following code highlights show how we would abstract the logging operations.
public interface OperationalLogger { public boolean isInfoEnabled(LogEntity entity); public void info(LogEntity entity, Object message); public void info(LogEntity entity , Object message, Throwable throwable); // Repeated for each level TRACE|DEBUG|INFO|WARN|ERROR|FATAL } |
public interface LogEntity { public String getLogPrefix(); public void setCreator(LogEntity creator); } |
The LogEntity allows the OperationLogger to delegate the creation of the formated prefix as specfiecied here. Further additions to this interface may be required to enable selective configurations however this is not part of this design.
The addition of the ability to set a creator allows for situations such as Binding to have a Connection associated with the Binding. This will allow a Binding create event to be logged like this:
2009-06-29 13:35:10,1234 +0100 INFO [ con:1(guest@127.0.0.1/)/ch:2/ex(amq.direct)/qu(testQueue)/bd(routingKey) ] Created Binding |
rather having no details about how the creation occured:
2009-06-29 13:35:10,1234 +0100 INFO [ vh(/)/ex(amq.direct)/qu(testQueue)/bd(routingKey) ] Created Binding |
pubic class Subscription ... if (_statusLogger.isInfoEnabled(this)) { _statusLogger.info(this, "Subscription Event occured."); } ... |
Would result in the following based on the Logging Format Design.
2009-06-29 13:35:10,1234 +0100 INFO [ con:1(guest@127.0.0.1/)/ch:2/sub:1:qu(myqueue) ] Subscription Event occcured. |
... binding = new ExchangeBinding(...); ((LogEntity)binding).setCreator(connection); ... // Verify binding can be performed/created ... if (_statusLogger.isInfoEnabled(binding)) { _statusLogger.info(binding, "Created"); } ... |
Would result in the following:
2009-06-29 13:35:10,1234 +0100 INFO [ con:1(guest@127.0.0.1/)/ch:2/pl(ACL, Consume, qu(myQueue)) ] Plugin Event occured for this. |
At this level it is only expected that broker/virtualhost wide components could cause a FATAL issue.
MetaData not Found
Startup errors
Startup errors
UserManagement notification(Create, Update, Delete)
Access Right modification/reload
Recover errors
Unhandled exceptions leading to connection closure
Unclean connection closure
Unsupported protocol version
Startup
Configuration details
Ready
Shutdown
Startup
Configuration details
Ready
Close
Create
Configuration details
Close
Startup
Recover Status
Close
Open
Close
Create
Flow Status
Destroy
Create
Destroy
Create
Destroy
Create
Destroy
Create
Destroy
Message Expiry
Creation Configuration details
Acknowledge
Commit
MessageRejection
Enqueue
Dequeue
Route
Send/Add to prefetch/unacked map
Enqueue
Dequeue
Message State Change(Available->Aquire...)