...
Table of Contents | ||||
---|---|---|---|---|
|
Logging Control
Initialy the use of a properties file will be used to enable/disable various logging options. The property value will be one of a set list. This will help avoid the ambigious parsing of Java Properties files.
No Format | ||
---|---|---|
| ||
# Comment Line
<logger> = <value [OFF|TRACE|DEBUG|INFO|WARN|ERROR|FATAL|ALL]>
|
The values for the <logger> are based on navigation through the hierarchy.
Hierarchy Refinement
...
qpid ─┬─ broker
│
│
│ ┌── [<username>] ───┐
│ ├─ [<ip/hostname>] ─┤
├─ connection ─┴───── [<id>] ──────┴─ channel ── [<id>] ──────┬── subscription ── [<id>]
│ │
└─ virtualHost ── <name> ─┐ ┌─ binding │
│ │ │
├─ exchange ── <name> ─┤ │
│ │ │
├─ queue ── <name> ────┴────────────┘
│
├─ plugin ── <name>
│
└─ messagestore
At this state the configurability of logging will be limited to selection of logging level. Further details on the approach to provide configurable logging can be found here.
Logging Levels
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
This hierachy has a number of paths which make it more difficult to process.
- Connection can be optionally followed with up to one of the following: username,ip/host, id
- Subscription can be reached through Connection and Virtualhost
- Exchange and Queue can be added in either order
- Binding can be routed through Queue and Exchange, or both in either order.
It is these difficulties that make it best to provide an abstraction layer so that a simple interface can be used at the site of the logging. These difficulties can be distilled to:
- Procsessing values for all values of '<name>'
- Overlapping configuration resolution
- Presentation of entities with multiple paths
Procsessing values for all values of '<name>'
To ensure that the logger path is processable the '<name>' must be present to make it easier to understand when we have an identifier or a <name> value. i.e. Is this logging all events for exchanges on Virtualhost called 'queue' or logging all exchange events that occur in relatation to queues.
No Format |
---|
qpid.virtualhost.queue.exchange = INFO
|
By introducing the use of the '*' wild card we can make these two situations easier to read:
No Format |
---|
qpid.virtualhost.queue.exchange = INFO
qpid.virtualhost.*.queue.exchange = INFO
|
The '*' can then be used at the end of the logger to ensure all logging from this point in the hierarchy will be logged, rather than just events to the specified entity.
Overlapping configuration resolution
The loops in the graph will be handled by the logger configurator so that only one log entry is created for each event, even if there are multiple matching entries in the configuration. For example, the follow two entries are equivalent and will both enable all loging for bindings. If the user wishes to log all binding operations then only one entry is necessary but the presence of both should not cause duplicate messages.
No Format | ||
---|---|---|
| ||
qpid.virtualhost.*.exchange.*.binding = INFO
qpid.virtualhost.*.queue.*.binding = INFO
|
The overlapping of configuration such as logging all details of connection from user guest and from ip 127.0.0.1 will not result in a duplicated logging if guest connects from 127.0.0.1.
No Format | ||
---|---|---|
| ||
qpid.connection.guest.* = INFO
qpid.connection.<127.0.0.1>.* = INFO
|
Presentation of entities with multiple paths
Each entitiy will have a prescribed log format which will be designed to take into consideration its place in the hierarchy, see Logging Format Design for further details.
Log Configuration processing
The configuration will be processed top-to-bottom. This allows for defaults to be set and specific cases to have further logging enabled. The example below enables INFO logging for all events and specifically adds DEBUG logging for all activity related to the user 'guest'.
...
title | Example Control File |
---|
...
Logging Abstraction
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.
Code Block | |||||||
---|---|---|---|---|---|---|---|
| |||||||
public interface OperationalLogger { public boolean isInfoEnabledForPluginisInfoEnabled(Plugin p, Object oLogEntity entity); public void pluginInfoinfo(PluginLogEntity pentity, Object omessage); public void pluginInfoinfo(PluginLogEntity entity p, Object omessage, Throwable throwable); // Repeated for each level public boolean isInfoEnabled(Object o);TRACE|DEBUG|INFO|WARN|ERROR|FATAL } |
Code Block | ||||||
---|---|---|---|---|---|---|
| ||||||
public interface LogEntity { public voidString infogetLogPrefix(Object o); public void infosetCreator(Object o, Throwable throwableLogEntity creator); ... // Repeated for each level TRACE|DEBUG|INFO|WARN|ERROR|FATAL } |
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.
Logging Usage
Code Block | ||||||
---|---|---|---|---|---|---|
| ||||||
pubic class Subscription ... if (_statusLogger.isInfoEnabled(this)) { _statusLogger.info(this, "Subscription Event occured."); } ... |
...
No Format |
---|
2009-06-29 13:35:10,1234 +0100 [ con:1(guest, 127.0.0.1, /)/ch:2/sub:1:qu(myqueue) ] Subscription Event occcured. |
Code Block | ||||||
---|---|---|---|---|---|---|
| ||||||
pubic class Channel ... pluginbinding = getACLPlugin();new ExchangeBinding(...); ((LogEntity)binding).setCreator(connection); ... // Verify binding can be performed/created ... if (_statusLogger.isInfoEnabledForPlugin(plugin, thisisInfoEnabled(binding)) { _statusLogger.pluginInfo(plugin, thisinfo(binding, "Plugin Event occured for this.Created"); } ... |
Would result in the following:
No Format |
---|
2009-06-29 13:35:10,1234 +0100 [ con:1(guest, 127.0.0.1, /)/ch:2/pl(ACL, Consume, qu(myQueue)) ] Plugin Event occured for this. |
Initial Log Messages
...
FATAL
At this level it is only expected that broker/virtualhost wide components could cause a FATAL issue.
Broker
ManagementConsole
VirtualHost
MessageStore
MetaData not Found
ERROR
Broker
Startup errors
ManagementConsole
Startup errors
UserManagement notification(Create, Update, Delete)
Access Right modification/reload
VirtualHost
MessageStore
Recover errors
Connection
Unhandled exceptions leading to connection closure
Channel
Queue
Exchange
Binding
Subscription
WARN
Broker
ManagementConsole
VirtualHost
MessageStore
Connection
Unclean connection closure
Unsupported protocol version
Channel
Queue
Exchange
Binding
Subscription
INFO
Broker
Startup
Configuration details
Ready
Shutdown
ManagementConsole
Startup
Configuration details
Ready
Close
VirtualHost
Create
Configuration details
Close
MessageStore
Startup
Recover Status
Close
Connection
Open
Close
Channel
Create
Flow Status
Destroy
Queue
Create
Destroy
Exchange
Create
Destroy
Binding
Create
Destroy
Subscription
Create
Destroy
DEBUG
Broker
ManagementConsole
VirtualHost
Message Expiry
MessageStore
Connection
Creation Configuration details
Channel
Acknowledge
Commit
MessageRejection
Queue
Enqueue
Dequeue
Exchange
Route
Binding
Subscription
Send/Add to prefetch/unacked map
TRACE
Broker
ManagementConsole
VirtualHost
MessageStore
Enqueue
Dequeue
Connection
Channel
Queue
Message State Change(Available->Aquire...)