Logging Format Design
This design follows on from the high level design work to provide a more detailed description of the format that all logged messages will take. The design is split in to two sections:
- LogSubject Detail
- Log Formating
LogSubject Detail
Each LogSubject in the system has a format that for logging its own indentifier. It is invisaged that each Model instance will have a LogSubject member variable to act as a cache for their log format.
LogSubject Identifiers
The following is the basic LogSubject identifiers:
LogSubject |
Identifier |
|---|---|
Broker |
b |
MessageStore |
ms |
VirtualHost |
vh(<name>) |
Conection |
con:<uid>(<username>@<ip>/<vhost-name>) |
Channel |
ch:<uid> |
Queue |
qu(<queueName>) |
Exchange |
ex(<exchangeName>) |
Binding |
bd(<routingKey>) |
Subscription |
sub:<uid>:qu(<queueName>) |
Plugin |
pl(name[, <optional values>]*) |
The plugin format allows for simple identification of the plugin such as 'ACL', 'Firewall' as well as giving the plugin the option to extend its base format. This extension is to allow easy processing of the log file.
LogSubject Paths
Broker, VirtualHost & Connection are root identifiers which means no parent nodes need be pre-appended to the log statement.
LogSubject |
Log Path |
Example |
|---|---|---|
MessageStore |
vh(name)/ms |
[ vh(/)/ms ] |
Channel |
<Connection>/ch:<uid> |
[ con:1(user@127.0.0.1/)/ch:1 ] |
Queue |
<Virtualhost>/qu(<queueName>) |
[ vh(/)/qu(testQueue) ] |
Exchange |
<Virtualhost>/ex(<exchangeName>) |
[ vh(/)/ex(amq.direct) ] |
Binding |
<Virtualhost>/<Exchange>/<Queue>/bd(<routingKey>) |
[ vh(/)/ex(amq.direct)/qu(testQueue)/bd(testQueue) ] |
Subscription |
sub:<uid>:qu(<queue-name>) |
[sub:2:qu(testQueue)] |
Plugin |
<Entity>/pl(name[, <optional values>]*) |
[pl(ACL, Consume, qu(testQueue))] |
The plugin entitiy allows for plugins to log additional details about their operation on an entity. For example as shown above an ACL plugin can log details about the attempt to consume from Queue 'testQueue'.
Log Formatting
To ensure that all log messages are displayed consistently the logging framework will provide the Datetime and Entity details, the requested log message will be added to the end this preamble:
<ISO-8601 Datetime (UTC based w/ TZ)> <Logging Level> [ <LogActor> ] [ <LogSubject> ] <LogMessage>
2009-06-29 13:35:10,1234 +0100 Message [con:1(user@127.0.0.1/)/ch:2] [sub:1:qu(myqueue)] Subscription Event Occcured
2 Comments
Aidan Skinner
The entity format is horrible. Basically unparsable with anything less than a regex. How about:
<username>@<host>:<remote-port>:<channel>:<virtualhost>:[queue|exchange/binding|subscription]
The example:
2009-06-29 13:35:10,1234 +0100 [ con:1(guest, 127.0.0.1, /)/ch:2/sub:1(myqueue) ] Subscription Event Occcured
Becomes:
2009-06-29 13:35:10,1234 +0100 [ guest@127.0.0.1:2452:2:1/vhost/myqueue ] Subscription Event Occcured
Or on publish
2009-06-29 13:35:10,1234 +0100 [ guest@127.0.0.1:2452:2/vhost/amq.direct/myqueue ] Publish Event Occcured
Which makes it trivial to grep for all the events related to myqueue on vhost.
Martin Ritchie
Agree that having a regex is undesirable. If I understand your objections correctly they around the inconsistency with queue display and selecting conection details.
To answer your points I think if we always follow the queue format qu(<name>) then it will be easy to extract. So the subscription event would be come:
2009-06-29 13:35:10,1234 +0100 [ con:1(user@127.0.0.1/)/ch:2/sub:1:qu(myqueue) ] Subscription Event Occcured
The benefit of this is a single simple grep for the qu(myqueue) will find all log statements that were for that queue.
The other change is to the connection details: con:1(user@127.0.0.1/) I think this is more understandable form a user's point of view and still machine parsable.
I think this encorporates the main points of your suggestion. I'm not convinced by the sequence of '<host>:<remote-port>:<channel>:<virtualhost>:' as this is not easily understood by a human operator.