Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Logger dumps error with classname #899

Merged
merged 4 commits into from
Apr 20, 2016
Merged

Logger dumps error with classname #899

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
b03d1da
fix to dump error object with its class and message
tagomoris Apr 15, 2016
a720cde
no more "error_class: error.class, error: e.to_s"
tagomoris Apr 15, 2016
50b5701
change format with previous style
tagomoris Apr 19, 2016
67ede0b
dump error only when other keys doesn't exist
tagomoris Apr 19, 2016
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 3 additions & 3 deletions lib/fluent/agent.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -84,7 +84,7 @@ def shutdown
log.info "shutting down filter#{@context.nil? ? '' : " in #{@context}"}", type: Plugin.lookup_type_from_class(f.class), plugin_id: f.plugin_id
f.shutdown
rescue => e
log.warn "unexpected error while shutting down filter plugins", plugin: f.class, plugin_id: f.plugin_id, error_class: e.class, error: e
log.warn "unexpected error while shutting down filter plugins", plugin: f.class, plugin_id: f.plugin_id, error: e
log.warn_backtrace
end
end
Expand All @@ -98,7 +98,7 @@ def shutdown
log.info "shutting down output#{@context.nil? ? '' : " in #{@context}"}", type: Plugin.lookup_type_from_class(o.class), plugin_id: o.plugin_id
o.shutdown
rescue => e
log.warn "unexpected error while shutting down output plugins", plugin: o.class, plugin_id: o.plugin_id, error_class: e.class, error: e
log.warn "unexpected error while shutting down output plugins", plugin: o.class, plugin_id: o.plugin_id, error: e
log.warn_backtrace
end
end
Expand All @@ -118,7 +118,7 @@ def flush_recursive(array)
flush_recursive(o.outputs)
end
rescue => e
log.debug "error while force flushing", error_class: e.class, error: e
log.debug "error while force flushing", error: e
log.debug_backtrace
end
}
Expand Down
4 changes: 2 additions & 2 deletions lib/fluent/engine.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -166,7 +166,7 @@ def log_event_loop
begin
@event_router.emit(tag, time, record)
rescue => e
$log.error "failed to emit fluentd's log event", tag: tag, event: record, error_class: e.class, error: e
$log.error "failed to emit fluentd's log event", tag: tag, event: record, error: e
end
}
end
Expand Down Expand Up @@ -195,7 +195,7 @@ def run
end

rescue => e
$log.error "unexpected error", error_class: e.class, error: e
$log.error "unexpected error", error: e
$log.error_backtrace
ensure
$log.info "shutting down fluentd"
Expand Down
6 changes: 5 additions & 1 deletion lib/fluent/log.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -292,7 +292,11 @@ def event(level, args)
}

map.each_pair {|k,v|
message << " #{k}=#{v.inspect}"
if k == "error".freeze && v.is_a?(Exception) && !map.has_key?("error_class")
message << " error_class=#{v.class.to_s} error=#{v.to_s.inspect}"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

v would be a string like

fluentd/lib/fluent/output.rb

Line 127 in 88054a0

$log.error "error on output thread", error: $!.to_s
, so need to add and v.is_a?(Exception).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Need to add another condition !map.has_key?('error_class'), otherwirse, error_class= appears twice for old codes such as:

log.error 'message', error_class: e.class, error: e

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's right. I fixed so.

else
message << " #{k}=#{v.inspect}"
end
}

unless @threads_exclude_events.include?(Thread.current)
Expand Down
14 changes: 7 additions & 7 deletions lib/fluent/output.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -329,28 +329,28 @@ def try_flush
end

if @disable_retry_limit || error_count < @retry_limit
$log.warn "temporarily failed to flush the buffer.", next_retry: Time.at(@next_retry_time), error_class: e.class.to_s, error: e.to_s, plugin_id: plugin_id
$log.warn "temporarily failed to flush the buffer.", next_retry: Time.at(@next_retry_time), error: e, plugin_id: plugin_id
$log.warn_backtrace e.backtrace

elsif @secondary
if error_count == @retry_limit
$log.warn "failed to flush the buffer.", error_class: e.class.to_s, error: e.to_s, plugin_id: plugin_id
$log.warn "failed to flush the buffer.", error: e, plugin_id: plugin_id
$log.warn "retry count exceededs limit. falling back to secondary output."
$log.warn_backtrace e.backtrace
retry # retry immediately
elsif error_count <= @retry_limit + @secondary_limit
$log.warn "failed to flush the buffer, next retry will be with secondary output.", next_retry: Time.at(@next_retry_time), error_class: e.class.to_s, error: e.to_s, plugin_id: plugin_id
$log.warn "failed to flush the buffer, next retry will be with secondary output.", next_retry: Time.at(@next_retry_time), error: e, plugin_id: plugin_id
$log.warn_backtrace e.backtrace
else
$log.warn "failed to flush the buffer.", error_class: e.class, error: e.to_s, plugin_id: plugin_id
$log.warn "failed to flush the buffer.", error: e, plugin_id: plugin_id
$log.warn "secondary retry count exceededs limit."
$log.warn_backtrace e.backtrace
write_abort
@num_errors = 0
end

else
$log.warn "failed to flush the buffer.", error_class: e.class.to_s, error: e.to_s, plugin_id: plugin_id
$log.warn "failed to flush the buffer.", error: e, plugin_id: plugin_id
$log.warn "retry count exceededs limit."
$log.warn_backtrace e.backtrace
write_abort
Expand All @@ -373,7 +373,7 @@ def before_shutdown
begin
@buffer.before_shutdown(self)
rescue
$log.warn "before_shutdown failed", error: $!.to_s
$log.warn "before_shutdown failed", error: $!
$log.warn_backtrace
end
end
Expand All @@ -395,7 +395,7 @@ def write_abort
begin
@buffer.clear!
rescue
$log.error "unexpected error while aborting", error: $!.to_s
$log.error "unexpected error while aborting", error: $!
$log.error_backtrace
end
end
Expand Down
2 changes: 1 addition & 1 deletion lib/fluent/plugin/filter_grep.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -70,7 +70,7 @@ def filter(tag, time, record)
result = record
end
rescue => e
log.warn "failed to grep events", error_class: e.class, error: e.message
log.warn "failed to grep events", error: e
log.warn_backtrace
end
result
Expand Down
6 changes: 3 additions & 3 deletions lib/fluent/plugin/filter_record_transformer.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -107,7 +107,7 @@ def filter_stream(tag, es)
end
new_es
rescue => e
log.warn "failed to reform records", error_class: e.class, error: e.message
log.warn "failed to reform records", error: e
log.warn_backtrace
log.debug "map:#{@map} record:#{last_record} placeholder_values:#{placeholder_values}"
end
Expand All @@ -121,7 +121,7 @@ def parse_value(value_str)
value_str
end
rescue => e
log.warn "failed to parse #{value_str} as json. Assuming #{value_str} is a string", error_class: e.class, error: e.message
log.warn "failed to parse #{value_str} as json. Assuming #{value_str} is a string", error: e
value_str # emit as string
end

Expand Down Expand Up @@ -307,7 +307,7 @@ def expand(str, placeholders, force_stringify = false)
placeholders['hostname'],
)
rescue => e
log.warn "failed to expand `#{str}`", error_class: e.class, error: e.message
log.warn "failed to expand `#{str}`", error: e
log.warn_backtrace
nil
end
Expand Down
4 changes: 2 additions & 2 deletions lib/fluent/plugin/in_exec.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -149,7 +149,7 @@ def run_periodic
Process.waitpid(io.pid)
sleep @run_interval
rescue
log.error "exec failed to run or shutdown child process", error: $!.to_s, error_class: $!.class.to_s
log.error "exec failed to run or shutdown child process", error: $!
log.warn_backtrace $!.backtrace
end
end
Expand All @@ -176,7 +176,7 @@ def on_message(record, parsed_time = nil)

router.emit(tag, time, record)
rescue => e
log.error "exec failed to emit", error: e.to_s, error_class: e.class.to_s, tag: tag, record: Yajl.dump(record)
log.error "exec failed to emit", error: e, tag: tag, record: Yajl.dump(record)
end
end
end
2 changes: 1 addition & 1 deletion lib/fluent/plugin/in_forward.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -106,7 +106,7 @@ def listen
def run
@loop.run(@blocking_timeout)
rescue => e
log.error "unexpected error", error: e, error_class: e.class
log.error "unexpected error", error: e
log.error_backtrace
end

Expand Down
2 changes: 1 addition & 1 deletion lib/fluent/plugin/in_object_space.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -115,7 +115,7 @@ def on_timer

router.emit(@tag, now, record)
rescue => e
log.error "object space failed to emit", error: e.to_s, error_class: e.class.to_s, tag: @tag, record: Yajl.dump(record)
log.error "object space failed to emit", error: e, tag: @tag, record: Yajl.dump(record)
end
end
end
2 changes: 1 addition & 1 deletion lib/fluent/plugin/in_syslog.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -200,7 +200,7 @@ def emit(pri, time, record)

router.emit(tag, time, record)
rescue => e
log.error "syslog failed to emit", error: e.to_s, error_class: e.class.to_s, tag: tag, record: Yajl.dump(record)
log.error "syslog failed to emit", error: e, tag: tag, record: Yajl.dump(record)
end
end
end
2 changes: 1 addition & 1 deletion lib/fluent/plugin/out_exec_filter.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -383,7 +383,7 @@ def on_message(record)
router.emit(tag, time, record)
rescue
if @suppress_error_log_interval == 0 || Time.now.to_i > @next_log_time
log.error "exec_filter failed to emit", error: $!.to_s, error_class: $!.class.to_s, record: Yajl.dump(record)
log.error "exec_filter failed to emit", error: $!, record: Yajl.dump(record)
log.warn_backtrace $!.backtrace
@next_log_time = Time.now.to_i + @suppress_error_log_interval
end
Expand Down
8 changes: 4 additions & 4 deletions lib/fluent/plugin/socket_util.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,7 +46,7 @@ def on_readable
msg.chomp!
@callback.call(msg, addr)
rescue => e
@log.error "unexpected error", error: e, error_class: e.class
@log.error "unexpected error", error: e
end
end

Expand Down Expand Up @@ -82,7 +82,7 @@ def on_read(data)
end
@buffer.slice!(0, pos) if pos > 0
rescue => e
@log.error "unexpected error", error: e, error_class: e.class
@log.error "unexpected error", error: e
close
end

Expand Down Expand Up @@ -133,7 +133,7 @@ def shutdown
def run
@loop.run(@blocking_timeout)
rescue => e
log.error "unexpected error", error: e, error_class: e.class
log.error "unexpected error", error: e
log.error_backtrace
end

Expand All @@ -150,7 +150,7 @@ def on_message(msg, addr)
router.emit(@tag, time, record)
}
rescue => e
log.error msg.dump, error: e, error_class: e.class, host: addr[3]
log.error msg.dump, error: e, host: addr[3]
log.error_backtrace
end
end
Expand Down
6 changes: 3 additions & 3 deletions lib/fluent/plugin/storage_local.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ def configure(conf, plugin)
data = Yajl::Parser.parse(open(@path, 'r:utf-8'){ |io| io.read })
raise Fluent::ConfigError, "Invalid contents (not object) in plugin storage file: '#{@path}'" unless data.is_a?(Hash)
rescue => e
log.error "failed to read data from plugin storage file", path: @path, error_class: e.class, error: e
log.error "failed to read data from plugin storage file", path: @path, error: e
raise Fluent::ConfigError, "Unexpected error: failed to read data from plugin storage file: '#{@path}'"
end
else
Expand All @@ -71,7 +71,7 @@ def load
end
@store = json
rescue => e
log.error "failed to load data for plugin storage from file", path: @path, error_class: e.class, error: e
log.error "failed to load data for plugin storage from file", path: @path, error: e
end
end

Expand All @@ -83,7 +83,7 @@ def save
open(tmp_path, 'w:utf-8', @mode){ |io| io.write json_string }
File.rename(tmp_path, @path)
rescue => e
log.error "failed to save data for plugin storage to file", path: @path, tmp: tmp_path, error_class: e.class, error: e
log.error "failed to save data for plugin storage to file", path: @path, tmp: tmp_path, error: e
end
end

Expand Down
4 changes: 2 additions & 2 deletions lib/fluent/plugin_helper/child_process.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -272,10 +272,10 @@ def child_process_execute_once(
if e.message == 'stream closed'
log.debug "Process I/O stream closed", title: title, pid: pid, command: command, arguments: arguments
else
log.error "Unexpected I/O error for child process", title: title, pid: pid, command: command, arguments: arguments, error_class: e.class, error: e
log.error "Unexpected I/O error for child process", title: title, pid: pid, command: command, arguments: arguments, error: e
end
rescue => e
log.warn "Unexpected error while processing I/O for child process", title: title, pid: pid, command: command, error_class: e.class, error: e
log.warn "Unexpected error while processing I/O for child process", title: title, pid: pid, command: command, error: e
end
process_info = @_child_process_mutex.synchronize do
process_info = @_child_process_processes[pid]
Expand Down
8 changes: 4 additions & 4 deletions lib/fluent/plugin_helper/storage.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@ def storage_create(usage: '', type: nil, conf: nil)
begin
s.storage.save
rescue => e
log.error "plugin storage failed to save its data", usage: usage, type: type, error_class: e.class, error: e
log.error "plugin storage failed to save its data", usage: usage, type: type, error: e
end
end
end
Expand Down Expand Up @@ -115,7 +115,7 @@ def shutdown
begin
s.storage.save if s.storage.save_at_shutdown
rescue => e
log.error "unexpected error while saving data of plugin storages", usage: usage, storage: s.storage, error_class: e.class, error: e
log.error "unexpected error while saving data of plugin storages", usage: usage, storage: s.storage, error: e
end
end

Expand All @@ -127,7 +127,7 @@ def close
begin
s.storage.close
rescue => e
log.error "unexpected error while closing plugin storages", usage: usage, storage: s.storage, error_class: e.class, error: e
log.error "unexpected error while closing plugin storages", usage: usage, storage: s.storage, error: e
end
s.running = false
end
Expand All @@ -140,7 +140,7 @@ def terminate
begin
s.storage.terminate
rescue => e
log.error "unexpected error while terminating plugin storages", usage: usage, storage: s.storage, error_class: e.class, error: e
log.error "unexpected error while terminating plugin storages", usage: usage, storage: s.storage, error: e
end
end
@_storages = {}
Expand Down
2 changes: 1 addition & 1 deletion lib/fluent/plugin_helper/thread.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,7 @@ def thread_create(title)
yield
thread_exit = true
rescue => e
log.warn "thread exited by unexpected error", plugin: self.class, title: title, error_class: e.class, error: e
log.warn "thread exited by unexpected error", plugin: self.class, title: title, error: e
thread_exit = true
raise
ensure
Expand Down
2 changes: 1 addition & 1 deletion lib/fluent/plugin_helper/timer.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ def initialize(title, interval, repeat, log, checker, &callback)
def on_timer
@callback.call if @checker.call
rescue => e
@log.error "Unexpected error raised. Stopping the timer.", title: @title, error: e, error_class: e.class
@log.error "Unexpected error raised. Stopping the timer.", title: @title, error: e
@log.error_backtrace
self.detach
@log.error "Timer detached.", title: @title
Expand Down
10 changes: 5 additions & 5 deletions lib/fluent/root_agent.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -126,7 +126,7 @@ def shutdown
log.info "shutting down input", type: Plugin.lookup_type_from_class(i.class), plugin_id: i.plugin_id
i.shutdown
rescue => e
log.warn "unexpected error while shutting down input plugin", plugin: i.class, plugin_id: i.plugin_id, error_class: e.class, error: e
log.warn "unexpected error while shutting down input plugin", plugin: i.class, plugin_id: i.plugin_id, error: e
log.warn_backtrace
end
end
Expand Down Expand Up @@ -173,7 +173,7 @@ def find_label(label_name)
end

def emit_error_event(tag, time, record, error)
error_info = {error_class: error.class, error: error.to_s, tag: tag, time: time}
error_info = {error: error, tag: tag, time: time}
if @error_collector
# A record is not included in the logs because <@ERROR> handles it. This warn is for the notification
log.warn "send an error event to @ERROR:", error_info
Expand All @@ -185,7 +185,7 @@ def emit_error_event(tag, time, record, error)
end

def handle_emits_error(tag, es, error)
error_info = {error_class: error.class, error: error.to_s, tag: tag}
error_info = {error: error, tag: tag}
if @error_collector
log.warn "send an error event stream to @ERROR:", error_info
@error_collector.emit_stream(tag, es)
Expand Down Expand Up @@ -214,14 +214,14 @@ def initialize(root_agent)
end

def emit_error_event(tag, time, record, error)
error_info = {error_class: error.class, error: error.to_s, tag: tag, time: time, record: record}
error_info = {error: error, tag: tag, time: time, record: record}
log.warn "dump an error event in @ERROR:", error_info
end

def handle_emits_error(tag, es, e)
now = Engine.now
if @suppress_emit_error_log_interval.zero? || now > @next_emit_error_log_time
log.warn "emit transaction failed in @ERROR:", error_class: e.class, error: e, tag: tag
log.warn "emit transaction failed in @ERROR:", error: e, tag: tag
log.warn_backtrace
@next_emit_error_log_time = now + @suppress_emit_error_log_interval
end
Expand Down