From 5c41d803a179dc0e8ac0a2548e794c3b6ef3bcf2 Mon Sep 17 00:00:00 2001 From: Thom May Date: Fri, 19 Jan 2018 13:15:41 +0000 Subject: add metadata to log messages Signed-off-by: Thom May --- lib/mixlib/log.rb | 41 ++++++------------ lib/mixlib/log/child.rb | 28 ++++-------- lib/mixlib/log/formatter.rb | 14 +++++- lib/mixlib/log/logger.rb | 103 ++++++++++++++++++++++++++++++++++++++++++++ lib/mixlib/log/logging.rb | 56 ++++++++++++++++++++++++ 5 files changed, 193 insertions(+), 49 deletions(-) create mode 100644 lib/mixlib/log/logger.rb create mode 100644 lib/mixlib/log/logging.rb (limited to 'lib/mixlib') diff --git a/lib/mixlib/log.rb b/lib/mixlib/log.rb index c6dc839..2161568 100644 --- a/lib/mixlib/log.rb +++ b/lib/mixlib/log.rb @@ -20,15 +20,14 @@ require "logger" require "mixlib/log/version" require "mixlib/log/formatter" require "mixlib/log/child" +require "mixlib/log/logging" module Mixlib module Log + include Logging @logger, @loggers = nil - LEVELS = { :debug => Logger::DEBUG, :info => Logger::INFO, :warn => Logger::WARN, :error => Logger::ERROR, :fatal => Logger::FATAL }.freeze - LEVEL_NAMES = LEVELS.invert.freeze - def reset! close! @logger, @loggers = nil, nil @@ -70,19 +69,6 @@ module Mixlib @configured = true end - def with_child - child = Child.new(self) - if block_given? - yield child - else - child - end - end - - def pass(severity, args, progname = nil, &block) - add(severity, args, progname, &block) - end - # Use Mixlib::Log.init when you want to set up the logger manually. Arguments to this method # get passed directly to Logger.new, so check out the documentation for the standard Logger class # to understand what to do here. @@ -97,6 +83,7 @@ module Mixlib @logger.level = Logger::WARN @configured = true @parent = nil + @metadata = {} @logger end @@ -128,16 +115,6 @@ module Mixlib end end - # Define the standard logger methods on this class programmatically. - # No need to incur method_missing overhead on every log call. - [:debug, :info, :warn, :error, :fatal].each do |method_name| - class_eval(<<-METHOD_DEFN, __FILE__, __LINE__) - def #{method_name}(msg=nil, &block) - loggers.each {|l| l.#{method_name}(msg, &block) } - end - METHOD_DEFN - end - # Define the methods to interrogate the logger for the current log level. # Note that we *only* query the default logger (@logger) and not any other # loggers that may have been added, even though it is possible to configure @@ -154,8 +131,16 @@ module Mixlib loggers.each { |l| l << msg } end - def add(severity, message = nil, progname = nil, &block) - loggers.each { |l| l.add(severity, message, progname, &block) } + def add(severity, message = nil, progname = nil, data: {}, &block) + message, progname, data = yield if block_given? + data = metadata.merge(data) if data.kind_of?(Hash) + loggers.each do |l| + if l.respond_to?(:add_data) + l.add_data(severity, message, progname, data: data) + else + l.add(severity, message, progname) + end + end end alias :log :add diff --git a/lib/mixlib/log/child.rb b/lib/mixlib/log/child.rb index 2676b69..7234043 100644 --- a/lib/mixlib/log/child.rb +++ b/lib/mixlib/log/child.rb @@ -14,24 +14,23 @@ # See the License for the specific language governing permissions and # limitations under the License. +require "mixlib/log/logging" + module Mixlib module Log class Child - # include Mixlib::Log + include Mixlib::Log::Logging attr_reader :parent - def initialize(parent) + def initialize(parent, metadata = {}) @parent = parent + @metadata = metadata end def level parent.level end - def pass(severity, args, progname = nil, &block) - parent.pass(severity, args, progname, &block) - end - # Define the methods to interrogate the logger for the current log level. # Note that we *only* query the default logger (@logger) and not any other # loggers that may have been added, even though it is possible to configure @@ -39,23 +38,14 @@ module Mixlib [:debug?, :info?, :warn?, :error?, :fatal?].each do |method_name| class_eval(<<-METHOD_DEFN, __FILE__, __LINE__) def #{method_name} - parent.#{method_name} + parent.send(:#{method_name}) end METHOD_DEFN end - # Define the standard logger methods on this class programmatically. - # No need to incur method_missing overhead on every log call. - [:debug, :info, :warn, :error, :fatal].each do |method_name| - class_eval(<<-METHOD_DEFN, __FILE__, __LINE__) - def #{method_name}(msg=nil, &block) - pass(:#{method_name}, msg, &block) - end - METHOD_DEFN - end - - def add(severity, message = nil, progname = nil, &block) - parent.pass(severity, message, progname, &block) + def add(severity, message = nil, progname = nil, data: {}, &block) + data = metadata.merge(data) if data.kind_of?(Hash) + parent.send(:pass, severity, message, progname, data: data, &block) end end diff --git a/lib/mixlib/log/formatter.rb b/lib/mixlib/log/formatter.rb index c8f1efa..1727452 100644 --- a/lib/mixlib/log/formatter.rb +++ b/lib/mixlib/log/formatter.rb @@ -42,15 +42,25 @@ module Mixlib # put through "object.inspect" def msg2str(msg) case msg + when ::Hash + if msg.has_key?(:err) + format_exception(msg[:err]) + else + msg[:msg] + end when ::String msg when ::Exception - "#{msg.message} (#{msg.class})\n" << - (msg.backtrace || []).join("\n") + format_exception(msg) else msg.inspect end end + + def format_exception(msg) + "#{msg.message} (#{msg.class})\n" << + (msg.backtrace || []).join("\n") + end end end end diff --git a/lib/mixlib/log/logger.rb b/lib/mixlib/log/logger.rb new file mode 100644 index 0000000..c97be8e --- /dev/null +++ b/lib/mixlib/log/logger.rb @@ -0,0 +1,103 @@ +require "logger" + +# A subclass of Ruby's stdlib Logger with all the mutex and logrotation stuff +# ripped out, and metadata added in. +module Mixlib + module Log + class Logger < ::Logger + + # + # === Synopsis + # + # Logger.new(name, shift_age = 7, shift_size = 1048576) + # Logger.new(name, shift_age = 'weekly') + # + # === Args + # + # +logdev+:: + # The log device. This is a filename (String) or IO object (typically + # +STDOUT+, +STDERR+, or an open file). + # +shift_age+:: + # Number of old log files to keep, *or* frequency of rotation (+daily+, + # +weekly+ or +monthly+). + # +shift_size+:: + # Maximum logfile size (only applies when +shift_age+ is a number). + # + # === Description + # + # Create an instance. + # + def initialize(logdev) + @progname = nil + @level = DEBUG + @default_formatter = Formatter.new + @formatter = nil + @logdev = nil + if logdev + @logdev = LocklessLogDevice.new(logdev) + end + end + + def add_data(severity, message, progname, data: {}) + return true if @logdev.nil? || severity < @level + data ||= {} + if message.kind_of?(::Exception) + data[:err] = message + else + data[:msg] = message + end + @logdev.write( + format_message(format_severity(severity), Time.now, progname, data)) + true + end + + class LocklessLogDevice < LogDevice + + def initialize(log = nil) + @dev = @filename = @shift_age = @shift_size = nil + if log.respond_to?(:write) && log.respond_to?(:close) + @dev = log + else + @dev = open_logfile(log) + @filename = log + end + @dev.sync = true + end + + def write(message) + @dev.write(message) + rescue Exception => ignored + warn("log writing failed. #{ignored}") + end + + def close + @dev.close rescue nil + end + + private + + def open_logfile(filename) + if FileTest.exist?(filename) + open(filename, (File::WRONLY | File::APPEND)) + else + create_logfile(filename) + end + end + + def create_logfile(filename) + logdev = open(filename, (File::WRONLY | File::APPEND | File::CREAT)) + add_log_header(logdev) + logdev + end + + def add_log_header(file) + file.write( + "# Logfile created on %s by %s\n" % [Time.now.to_s, Logger::ProgName] + ) + end + + end + + end + end +end diff --git a/lib/mixlib/log/logging.rb b/lib/mixlib/log/logging.rb new file mode 100644 index 0000000..0e8aed9 --- /dev/null +++ b/lib/mixlib/log/logging.rb @@ -0,0 +1,56 @@ +# +# Copyright:: Copyright (c) 2018 Chef Software, Inc. +# License:: Apache License, Version 2.0 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +require "logger" +require "mixlib/log/child" + +module Mixlib + module Log + module Logging + + LEVELS = { :debug => Logger::DEBUG, :info => Logger::INFO, :warn => Logger::WARN, :error => Logger::ERROR, :fatal => Logger::FATAL }.freeze + LEVEL_NAMES = LEVELS.invert.freeze + + attr_accessor :metadata + + def pass(severity, args, progname = nil, data: {}, &block) + args, progname, data = yield if block_given? + add(severity, args, progname, data: data) + end + + # Define the standard logger methods on this class programmatically. + # No need to incur method_missing overhead on every log call. + [:debug, :info, :warn, :error, :fatal].each do |method_name| + level = LEVELS[method_name] + class_eval(<<-METHOD_DEFN, __FILE__, __LINE__) + def #{method_name}(msg=nil, data: {}, &block) + pass(#{level}, msg, data: data, &block) + end + METHOD_DEFN + end + + def with_child(metadata = {}) + child = Child.new(self, metadata) + if block_given? + yield child + else + child + end + end + + end + end +end -- cgit v1.2.1