Skip to content

Instantly share code, notes, and snippets.

@ttilley
Created October 8, 2012 18:25
Show Gist options
  • Save ttilley/3854055 to your computer and use it in GitHub Desktop.
Save ttilley/3854055 to your computer and use it in GitHub Desktop.
require 'eventmachine'
require 'digest/md5'
require 'fiber'
require 'thread'
unless defined?(ActiveSupport)
class String; def blank?; self !~ /[^[:space:]]/; end; end
class NilClass; def blank?; true; end; end
class Object; def blank?; false; end; end
end
class EMLogger
ProgName = $0
attr_accessor :progname
attr_accessor :level
alias sev_threshold level
alias sev_threshold= level=
module Severity # Logging severity.
TRACE = -1 # truly ludicrous and unnecessary verbosity
DEBUG = 0 # low-level information, mostly for developers
INFO = 1 # generic, useful information about system operation
WARN = 2 # a warning
ERROR = 3 # a handleable error condition
FATAL = 4 # an unhandleable error that results in a program crash
UNKNOWN = 5 # an unknown message that should always be logged
end
include Severity
SeverityMap = Severity.constants.inject({}) do |memo, name|
number = Severity.const_get(name)
memo[number] = name.to_s
memo
end
for severity in Severity.constants
class_eval <<-EOT, __FILE__, __LINE__ + 1
def #{severity.downcase}?
@level <= #{severity}
end
def #{severity.downcase}(message=nil, progname=nil, &block)
add(#{severity}, message, progname, &block)
end
EOT
end
class Formatter
attr_accessor :datetime_format
def initialize
@datetime_format = '[%F %T.%6N]'
end
def call(severity, time, progname, msg)
prefix = "#{format_time(time)} [#{severity}]#{tags_text} |"
msga = msg.respond_to?(:each) ?
msg.join("\n").split("\n") :
msg.split("\n")
msga.map! {|line| "#{prefix} #{line}"}
msga.join("\n") + "\n"
end
def tagged(*tags)
new_tags = push_tags(*tags)
yield self
ensure
pop_tags(new_tags.size)
end
def push_tags(*tags)
new_tags = tags.flatten.reject(&:blank?)
current_tags.concat new_tags
new_tags
end
def pop_tags(size=1)
current_tags.pop size
end
def clear_tags!
current_tags.clear
end
def current_tags
Thread.current[:emlogger_formatter_tags] ||= []
end
private
def tags_text
tags = current_tags
if tags.any?
' ' + tags.collect do |tag|
case tag
when ::String
tag
when :fiber_id
"fid=#{shortid(Fiber.current.object_id) rescue -1}"
when :thread_id
"tid=#{shortid(Thread.current.object_id) rescue -1}"
when :process_id
"pid=#{Process.pid rescue -1}"
else
tag.inspect
end
end.join(' ')
end
end
def shortid(data, len=4)
digest = Digest::MD5.hexdigest(data.to_s)
len = len > digest.length ? digest.length : len
digest[0, len]
end
def format_time(time)
time.strftime(@datetime_format)
end
end
attr_writer :formatter
def formatter
@formatter || @default_formatter
end
def format_message(severity, datetime, progname, msg)
formatter.call(severity, datetime, progname, msg)
end
def format_severity(severity)
SeverityMap[severity] || 'ANY'
end
def datetime_format=(datetime_format)
if formatter.respond_to?(:datetime_format=)
formatter.datetime_format = datetime_format
end
end
def datetime_format
formatter.datetime_format if formatter.respond_to?(:datetime_format)
end
def tagged(*tags)
if formatter.respond_to?(:tagged)
formatter.tagged(*tags) { yield self }
else
yield self
end
end
# set to false to disable the silencer defined below
def self.silencer; @@silencer; end
def silencer; @@silencer; end
def self.silencer=(obj); @@silencer = obj; end
def silencer=(obj); @@silencer = obj; end
@@silencer = true
# "silences" the logger by increasing its threshold for the duration of the
# block passed in to it. note that by default, only debug/info/warn level
# messages are silenced. this method may also be used to /increase/ logger
# sensitivity, and has been aliased as :with_level so that code using it for
# this purpose will make sense.
def silence(silence_level = ERROR)
if silencer
begin
natural_level, self.level = self.level, silence_level
yield self
ensure
self.level = natural_level
end
else
# silencer is disabled, act as normal
yield self
end
end
alias :with_level :silence
def silent?
@level >= ERROR
end
def silent=(bool)
if silencer and bool
@level = ERROR
elsif silencer and not bool
@level = INFO
end
end
class LogDevice
def initialize(log=nil, options={}, args=[])
@buffer = []
if log.respond_to?(:write) and log.respond_to?(:close)
@dev = log
else
@dev = open_logfile(log)
end
flush_interval = options[:flush_interval] || 0.5
timer = EventMachine::PeriodicTimer.new(flush_interval) do
begin
flush
rescue => e
STDERR.puts("Error while flushing log")
STDERR.puts(e)
timer.cancel
end
end
end
def write(message)
EM.schedule do
@buffer.push(message)
end
end
def close
flush do
@dev.flush
@dev.close
end
end
def flush(&blk)
return if @buffer.empty?
current, @buffer = @buffer, []
after_flush = block_given? ? blk : proc { @dev.flush }
EM.schedule do
EM::Iterator.new(current, 1).each(
proc {|message, iterator| @dev.write(message); iterator.next },
proc { @dev.flush }
)
end
end
private
def open_logfile(filename)
logdev = open(filename, (File::WRONLY | File::APPEND | File::CREAT))
logdev.sync = false
logdev
end
end
def initialize(logdev=nil, *args)
@default_formatter = ::EMLogger::Formatter.new
@progname = ProgName.dup
@level = DEBUG
options = args.last.is_a?(Hash) ? args.pop : {}
logdev ||= $stdout
@logdev = LogDevice.new(logdev, options, args)
end
def add(severity=UNKNOWN, message = nil, progname = nil, &block)
return true if @logdev.nil? or @level > severity
progname ||= @progname
message = (message || (block && block.call) || progname).to_s
@logdev.write(
format_message(format_severity(severity), Time.now, progname, message))
end
def <<(message)
@logdev.write(message + "\n")
end
def log(message=nil, progname=nil, &block)
add(INFO, message, progname, &block)
end
def log_error(e=$!)
add(ERROR, "#{e}\n\t" + e.backtrace.join("\n\t") + "\n")
end
def close
@logdev.close
end
end
if __FILE__ == $0
EM.run {
logger = EMLogger.new(STDOUT)
logger.log("moo")
begin
raise StandardError, "cows"
rescue => e
logger.log_error
end
logger.tagged :fiber_id, :thread_id do
logger.log "this should be tagged"
logger.log "so should this"
logger.tagged "wee" do
logger.log "this should have all previous tags plus 'wee'"
end
end
Fiber.new do |block|
block.call
end.resume(proc {
logger.tagged :fiber_id, :thread_id do
logger.log "I can haz Fiber"
end
})
EM.defer {
logger.tagged :fiber_id, :thread_id do
logger.log "this should have a new thread_id"
end
sleep 3
logger.log "this should enter the buffer three seconds after start"
}
logger.trace("trace")
logger.debug("debug")
logger.info("info")
logger.warn("warn")
logger.error("error")
logger.fatal("fatal")
logger.unknown("unknown")
EM.defer {
sleep 5
logger.close
EM.stop
}
}
end
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment