reidmorrison
Feature Suggestion: Per-logger tags
What do you think about allowing individual logger instances to carry their own tags? This would be particularly useful when loggers are owned by an object with an identity (e.g. an ActiveRecord instance).
To clarify what I mean, consider the following example:
class Cart < Entity
include SemanticLogging::Loggable
def add_item(item_id, quantity)
SemanticLogger.tagged(cart_id: self.id) do
InventoryService.reserve_items(item_id: item_id, quantity: quantity, reserved_by: self)
# do stuff, maybe a lot of stuff
logger.debug('added item', item_id: item_id, quantity: quantity)
end
end
def remove_item(item_id, quantity)
SemanticLogger.tagged(cart_id: self.id) do
InventoryService.cancel_item_reservation(item_id: item_id, quantity: quantity, reserved_by: self)
# again do a variety of things here
logger.debug('removed item', item_id: item_id, quantity: quantity)
end
end
end
As the number of methods grows, repeating SemanticLogger.tagged(cart_id: self.id) becomes tedious and leads to a lot of indenting. It also means all logging messages of the InventoryService are tagged with the current cart ID, which isn't always desirable.
What would be nice is if I could write this:
class Cart < Entity
include SemanticLogging::Loggable
def logger
@logger ||= super.with_tags(cart_id: self.id)
end
def add_item(item_id, quantity)
InventoryService.reserve_items(item_id: item_id, quantity: quantity, reserved_by: self)
# do more stuff here
logger.debug('added item', item_id: item_id, quantity: quantity)
end
def remove_item(item_id, quantity)
InventoryService.cancel_item_reservation(item_id: item_id, quantity: quantity, reserved_by: self)
# do other stuff here
logger.debug('removed item', item_id: item_id, quantity: quantity)
end
end
And in case I want the current #tagged behaviour:
class Cart < Entity
def add_item(other_cart)
logger.tagged do
# messages in this block are tagged with cart_id
InventoryService.reserve_items(item_id: item_id, quantity: quantity, reserved_by: self)
# do more stuff here
logger.debug('added item', item_id: item_id, quantity: quantity)
end
end
end
Yes, setting the logging tags on a per logger instance is a very interesting use case.
Rather than override the logger we could also setup the logger instance when the job is instantiated. Both approaches work well.
In this case separating tags from named_tags may be worthwhile, or otherwise detect if a hash or array is being assigned.
class Cart < Entity
include SemanticLogging::Loggable
def initialize
logger.named_tags = {cart_id: self.id}
end
def add_item(item_id, quantity)
InventoryService.reserve_items(item_id: item_id, quantity: quantity, reserved_by: self)
# do more stuff here
logger.debug('added item', item_id: item_id, quantity: quantity)
end
def remove_item(item_id, quantity)
InventoryService.cancel_item_reservation(item_id: item_id, quantity: quantity, reserved_by: self)
# do other stuff here
logger.debug('removed item', item_id: item_id, quantity: quantity)
end
end
The hardest part here is remaining backward compatible, with the existing methods that every logger instance already honors:
def tagged(*tags, &block)
# Allow named tags to be passed into the logger
if tags.size == 1
tag = tags[0]
return yield if tag.nil? || tag == ""
return tag.is_a?(Hash) ? SemanticLogger.named_tagged(tag, &block) : SemanticLogger.fast_tag(tag.to_s, &block)
end
# Need to flatten and reject empties to support calls from Rails 4
new_tags = tags.flatten.collect(&:to_s).reject(&:empty?)
SemanticLogger.tagged(*new_tags, &block)
end
# :nodoc:
alias with_tags tagged
# :nodoc:
def tags
SemanticLogger.tags
end
def named_tags
SemanticLogger.named_tags
end
The above behavior just passes the tags through to the thread specific log tags. Changing .with_tags or .tagged would significantly change the existing API. This would result in a lot of very surprised end users who the behavior they rely on suddenly changes.
Alternatively, we could create a new api to hold tags on a per logger instance basis that does not use the api .with_tags or .tagged.
Something like:
def named_tags=(named_tags)
(@named_tags ||= {}).merge(named_tags)
end
And then when the named tags are returned
def named_tags
SemanticLogger.named_tags.merge(@named_tags)
end
The next step is to verify that when the Log event is generated that it uses the named tags from this instance of the logger.
Unlike the SemanticLogger.tagged(cart_id: self.id) do block, log entries from other loggers in that block will not include these tags, only calls to the current logger. Not sure if that would be expected behavior.
Feel free to play around with it and look forward to your pull request.
