Class: Fluent::Plugin::Output
Defined Under Namespace
Classes: DequeuedChunkInfo, FlushThreadState, PlaceholderValidator
Constant Summary
collapse
- CHUNK_KEY_PATTERN =
/^[-_.@a-zA-Z0-9]+$/
- CHUNK_KEY_PLACEHOLDER_PATTERN =
/\$\{[-_.@a-zA-Z0-9]+\}/
- CHUNK_TAG_PLACEHOLDER_PATTERN =
/\$\{(tag(?:\[\d+\])?)\}/
- CHUNKING_FIELD_WARN_NUM =
4
- TIME_KEY_PLACEHOLDER_THRESHOLDS =
[
[1, :second, '%S'],
[60, :minute, '%M'],
[3600, :hour, '%H'],
[86400, :day, '%d'],
]
- TIMESTAMP_CHECK_BASE_TIME =
Time.parse("2016-01-01 00:00:00 UTC")
- FORMAT_MSGPACK_STREAM =
->(e){ e.to_msgpack_stream }
- FORMAT_COMPRESSED_MSGPACK_STREAM =
->(e){ e.to_compressed_msgpack_stream }
- FORMAT_MSGPACK_STREAM_TIME_INT =
->(e){ e.to_msgpack_stream(time_int: true) }
- FORMAT_COMPRESSED_MSGPACK_STREAM_TIME_INT =
->(e){ e.to_compressed_msgpack_stream(time_int: true) }
Configurable::CONFIG_TYPE_REGISTRY
Instance Attribute Summary collapse
#log
Attributes inherited from Base
#under_plugin_development
Instance Method Summary
collapse
-
#acts_as_secondary(primary) ⇒ Object
-
#after_shutdown ⇒ Object
-
#after_start ⇒ Object
-
#before_shutdown ⇒ Object
-
#close ⇒ Object
-
#commit_write(chunk_id, delayed: @delayed_commit, secondary: false) ⇒ Object
-
#configure(conf) ⇒ Object
-
#emit_buffered(tag, es) ⇒ Object
-
#emit_events(tag, es) ⇒ Object
-
#emit_sync(tag, es) ⇒ Object
-
#enqueue_thread_run ⇒ Object
-
#enqueue_thread_wait ⇒ Object
only for tests of output plugin.
-
#execute_chunking(tag, es, enqueue: false) ⇒ Object
-
#extract_placeholders(str, metadata) ⇒ Object
TODO: optimize this code.
-
#flush_thread_run(state) ⇒ Object
-
#flush_thread_wakeup ⇒ Object
only for tests of output plugin.
-
#force_flush ⇒ Object
-
#format(tag, time, record) ⇒ Object
-
#formatted_to_msgpack_binary ⇒ Object
-
#generate_format_proc ⇒ Object
-
#get_placeholders_keys(str) ⇒ Object
-
#get_placeholders_tag(str) ⇒ Object
-
#get_placeholders_time(str) ⇒ Object
it’s not validated to use timekey larger than 1 day.
-
#handle_stream_simple(tag, es, enqueue: false) ⇒ Object
-
#handle_stream_with_custom_format(tag, es, enqueue: false) ⇒ Object
metadata_and_data is a Hash of: (standard format) metadata => event stream (custom format) metadata => array of formatted event For standard format, formatting should be done for whole event stream, but “whole event stream” may be a split of “es” here when it’s bigger than chunk_limit_size.
-
#handle_stream_with_standard_format(tag, es, enqueue: false) ⇒ Object
-
#implement?(feature) ⇒ Boolean
-
#initialize ⇒ Output
constructor
output_enqueue_thread_waiting: for test of output.rb itself in_tests: for tests of plugins with test drivers.
-
#interrupt_flushes ⇒ Object
only for tests of output plugin.
-
#metadata(tag, time, record) ⇒ Object
TODO: optimize this code.
-
#metadata_for_test(tag, time, record) ⇒ Object
-
#next_flush_time ⇒ Object
-
#placeholder_validate!(name, str) ⇒ Object
-
#placeholder_validators(name, str, time_key = (@chunk_key_time && @buffer_config.timekey), tag_key = @chunk_key_tag, chunk_keys = @chunk_keys) ⇒ Object
-
#prefer_buffered_processing ⇒ Object
-
#prefer_delayed_commit ⇒ Object
-
#process(tag, es) ⇒ Object
-
#retry_state(randomize) ⇒ Object
-
#rollback_write(chunk_id) ⇒ Object
-
#shutdown ⇒ Object
-
#start ⇒ Object
-
#stop ⇒ Object
-
#submit_flush_all ⇒ Object
-
#submit_flush_once ⇒ Object
-
#support_in_v12_style?(feature) ⇒ Boolean
-
#terminate ⇒ Object
-
#try_flush ⇒ Object
-
#try_rollback_all ⇒ Object
-
#try_rollback_write ⇒ Object
-
#try_write(chunk) ⇒ Object
-
#write(chunk) ⇒ Object
-
#write_guard(&block) ⇒ Object
#dump_unique_id_hex, #generate_unique_id
included
included
#plugin_id, #plugin_id_configured?, #plugin_id_for_test?
Methods inherited from Base
#after_shutdown?, #after_started?, #before_shutdown?, #closed?, #configured?, #has_router?, #inspect, #shutdown?, #started?, #stopped?, #terminated?
#system_config, #system_config_override
#config, included, lookup_type, register_type
Constructor Details
#initialize ⇒ Output
output_enqueue_thread_waiting: for test of output.rb itself in_tests: for tests of plugins with test drivers
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
|
# File 'lib/fluent/plugin/output.rb', line 158
def initialize
super
@counters_monitor = Monitor.new
@buffering = false
@delayed_commit = false
@as_secondary = false
@in_tests = false
@primary_instance = nil
@num_errors = 0
@emit_count = 0
@emit_records = 0
@write_count = 0
@rollback_count = 0
if implement?(:synchronous)
if implement?(:buffered) || implement?(:delayed_commit)
@buffering = nil else
@buffering = false
end
else
@buffering = true
end
@custom_format = implement?(:custom_format)
@enable_msgpack_streamer = false
@buffer = nil
@secondary = nil
@retry = nil
@dequeued_chunks = nil
@output_enqueue_thread = nil
@output_flush_threads = nil
@simple_chunking = nil
@chunk_keys = @chunk_key_time = @chunk_key_tag = nil
@flush_mode = nil
@timekey_zone = nil
end
|
Instance Attribute Details
#as_secondary ⇒ Object
Returns the value of attribute as_secondary.
148
149
150
|
# File 'lib/fluent/plugin/output.rb', line 148
def as_secondary
@as_secondary
end
|
#buffer ⇒ Object
152
153
154
|
# File 'lib/fluent/plugin/output.rb', line 152
def buffer
@buffer
end
|
#chunk_key_tag ⇒ Object
152
153
154
|
# File 'lib/fluent/plugin/output.rb', line 152
def chunk_key_tag
@chunk_key_tag
end
|
#chunk_key_time ⇒ Object
152
153
154
|
# File 'lib/fluent/plugin/output.rb', line 152
def chunk_key_time
@chunk_key_time
end
|
#chunk_keys ⇒ Object
152
153
154
|
# File 'lib/fluent/plugin/output.rb', line 152
def chunk_keys
@chunk_keys
end
|
#delayed_commit ⇒ Object
Returns the value of attribute delayed_commit.
148
149
150
|
# File 'lib/fluent/plugin/output.rb', line 148
def delayed_commit
@delayed_commit
end
|
#delayed_commit_timeout ⇒ Object
Returns the value of attribute delayed_commit_timeout.
148
149
150
|
# File 'lib/fluent/plugin/output.rb', line 148
def delayed_commit_timeout
@delayed_commit_timeout
end
|
#emit_count ⇒ Object
Returns the value of attribute emit_count.
149
150
151
|
# File 'lib/fluent/plugin/output.rb', line 149
def emit_count
@emit_count
end
|
#emit_records ⇒ Object
Returns the value of attribute emit_records.
149
150
151
|
# File 'lib/fluent/plugin/output.rb', line 149
def emit_records
@emit_records
end
|
#in_tests ⇒ Object
Returns the value of attribute in_tests.
153
154
155
|
# File 'lib/fluent/plugin/output.rb', line 153
def in_tests
@in_tests
end
|
#num_errors ⇒ Object
Returns the value of attribute num_errors.
149
150
151
|
# File 'lib/fluent/plugin/output.rb', line 149
def num_errors
@num_errors
end
|
#output_enqueue_thread_waiting ⇒ Object
Returns the value of attribute output_enqueue_thread_waiting.
153
154
155
|
# File 'lib/fluent/plugin/output.rb', line 153
def output_enqueue_thread_waiting
@output_enqueue_thread_waiting
end
|
#retry ⇒ Object
152
153
154
|
# File 'lib/fluent/plugin/output.rb', line 152
def retry
@retry
end
|
#rollback_count ⇒ Object
Returns the value of attribute rollback_count.
149
150
151
|
# File 'lib/fluent/plugin/output.rb', line 149
def rollback_count
@rollback_count
end
|
#secondary ⇒ Object
152
153
154
|
# File 'lib/fluent/plugin/output.rb', line 152
def secondary
@secondary
end
|
#timekey_zone ⇒ Object
Returns the value of attribute timekey_zone.
148
149
150
|
# File 'lib/fluent/plugin/output.rb', line 148
def timekey_zone
@timekey_zone
end
|
#write_count ⇒ Object
Returns the value of attribute write_count.
149
150
151
|
# File 'lib/fluent/plugin/output.rb', line 149
def write_count
@write_count
end
|
Instance Method Details
#acts_as_secondary(primary) ⇒ Object
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
|
# File 'lib/fluent/plugin/output.rb', line 200
def acts_as_secondary(primary)
@as_secondary = true
@primary_instance = primary
@chunk_keys = @primary_instance.chunk_keys || []
@chunk_key_tag = @primary_instance.chunk_key_tag || false
if @primary_instance.chunk_key_time
@chunk_key_time = @primary_instance.chunk_key_time
@timekey_zone = @primary_instance.timekey_zone
@output_time_formatter_cache = {}
end
(class << self; self; end).module_eval do
define_method(:commit_write){ |chunk_id| @primary_instance.commit_write(chunk_id, delayed: delayed_commit, secondary: true) }
define_method(:rollback_write){ |chunk_id| @primary_instance.rollback_write(chunk_id) }
end
end
|
#after_shutdown ⇒ Object
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
|
# File 'lib/fluent/plugin/output.rb', line 449
def after_shutdown
try_rollback_all if @buffering && !@as_secondary @secondary.after_shutdown if @secondary
if @buffering && @buffer
@buffer.after_shutdown
@output_flush_threads_running = false
if @output_flush_threads && !@output_flush_threads.empty?
@output_flush_threads.each do |state|
state.thread.run if state.thread.alive? end
@output_flush_threads.each do |state|
state.thread.join
end
end
end
super
end
|
#after_start ⇒ Object
411
412
413
414
|
# File 'lib/fluent/plugin/output.rb', line 411
def after_start
super
@secondary.after_start if @secondary
end
|
#before_shutdown ⇒ Object
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
|
# File 'lib/fluent/plugin/output.rb', line 423
def before_shutdown
@secondary.before_shutdown if @secondary
if @buffering && @buffer
if @flush_at_shutdown
force_flush
end
@buffer.before_shutdown
@output_enqueue_thread_running = false
if @output_enqueue_thread && @output_enqueue_thread.alive?
@output_enqueue_thread.wakeup
@output_enqueue_thread.join
end
end
super
end
|
#close ⇒ Object
470
471
472
473
474
475
|
# File 'lib/fluent/plugin/output.rb', line 470
def close
@buffer.close if @buffering && @buffer
@secondary.close if @secondary
super
end
|
#commit_write(chunk_id, delayed: @delayed_commit, secondary: false) ⇒ Object
890
891
892
893
894
895
896
897
898
899
900
901
902
903
904
905
906
907
908
909
|
# File 'lib/fluent/plugin/output.rb', line 890
def commit_write(chunk_id, delayed: @delayed_commit, secondary: false)
log.trace "committing write operation to a chunk", chunk: dump_unique_id_hex(chunk_id), delayed: delayed
if delayed
@dequeued_chunks_mutex.synchronize do
@dequeued_chunks.delete_if{ |info| info.chunk_id == chunk_id }
end
end
@buffer.purge_chunk(chunk_id)
@retry_mutex.synchronize do
if @retry if secondary
log.warn "retry succeeded by secondary.", plugin_id: plugin_id, chunk_id: dump_unique_id_hex(chunk_id)
else
log.warn "retry succeeded.", plugin_id: plugin_id, chunk_id: dump_unique_id_hex(chunk_id)
end
@retry = nil
end
end
end
|
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
|
# File 'lib/fluent/plugin/output.rb', line 217
def configure(conf)
unless implement?(:synchronous) || implement?(:buffered) || implement?(:delayed_commit)
raise "BUG: output plugin must implement some methods. see developer documents."
end
has_buffer_section = (conf.elements(name: 'buffer').size > 0)
super
if has_buffer_section
unless implement?(:buffered) || implement?(:delayed_commit)
raise Fluent::ConfigError, "<buffer> section is configured, but plugin '#{self.class}' doesn't support buffering"
end
@buffering = true
else if implement?(:synchronous)
if !implement?(:buffered) && !implement?(:delayed_commit)
if @as_secondary
raise Fluent::ConfigError, "secondary plugin '#{self.class}' must support buffering, but doesn't."
end
@buffering = false
else
if @as_secondary
@buffering = true
else
@buffering = nil
end
end
else @buffering = true
end
end
if @as_secondary
if !@buffering && !@buffering.nil?
raise Fluent::ConfigError, "secondary plugin '#{self.class}' must support buffering, but doesn't"
end
end
if (@buffering || @buffering.nil?) && !@as_secondary
@chunk_keys = @buffer_config.chunk_keys.dup
@chunk_key_time = !!@chunk_keys.delete('time')
@chunk_key_tag = !!@chunk_keys.delete('tag')
if @chunk_keys.any?{ |key| key !~ CHUNK_KEY_PATTERN }
raise Fluent::ConfigError, "chunk_keys specification includes invalid char"
end
if @chunk_key_time
raise Fluent::ConfigError, "<buffer ...> argument includes 'time', but timekey is not configured" unless @buffer_config.timekey
Fluent::Timezone.validate!(@buffer_config.timekey_zone)
@timekey_zone = @buffer_config.timekey_use_utc ? '+0000' : @buffer_config.timekey_zone
@output_time_formatter_cache = {}
end
if (@chunk_key_tag ? 1 : 0) + @chunk_keys.size >= CHUNKING_FIELD_WARN_NUM
log.warn "many chunk keys specified, and it may cause too many chunks on your system."
end
@simple_chunking = !@chunk_key_time && @chunk_keys.empty?
@flush_mode = @buffer_config.flush_mode
if @flush_mode == :default
@flush_mode = (@chunk_key_time ? :lazy : :interval)
end
buffer_type = @buffer_config[:@type]
buffer_conf = conf.elements(name: 'buffer').first || Fluent::Config::Element.new('buffer', '', {}, [])
@buffer = Plugin.new_buffer(buffer_type, parent: self)
@buffer.configure(buffer_conf)
@flush_at_shutdown = @buffer_config.flush_at_shutdown
if @flush_at_shutdown.nil?
@flush_at_shutdown = if @buffer.persistent?
false
else
true end
elsif !@flush_at_shutdown && !@buffer.persistent?
buf_type = Plugin.lookup_type_from_class(@buffer.class)
log.warn "'flush_at_shutdown' is false, and buffer plugin '#{buf_type}' is not persistent buffer."
log.warn "your configuration will lose buffered data at shutdown. please confirm your configuration again."
end
end
if @secondary_config
raise Fluent::ConfigError, "Invalid <secondary> section for non-buffered plugin" unless @buffering
raise Fluent::ConfigError, "<secondary> section cannot have <buffer> section" if @secondary_config.buffer
raise Fluent::ConfigError, "<secondary> section cannot have <secondary> section" if @secondary_config.secondary
raise Fluent::ConfigError, "<secondary> section and 'retry_forever' are exclusive" if @buffer_config.retry_forever
secondary_type = @secondary_config[:@type]
unless secondary_type
secondary_type = conf['@type'] end
secondary_conf = conf.elements(name: 'secondary').first
@secondary = Plugin.new_output(secondary_type)
@secondary.acts_as_secondary(self)
@secondary.configure(secondary_conf)
@secondary.router = router if @secondary.has_router?
if (self.class != @secondary.class) && (@custom_format || @secondary.implement?(:custom_format))
log.warn "secondary type should be same with primary one", primary: self.class.to_s, secondary: @secondary.class.to_s
end
else
@secondary = nil
end
self
end
|
#emit_buffered(tag, es) ⇒ Object
704
705
706
707
708
709
710
711
712
713
714
715
716
|
# File 'lib/fluent/plugin/output.rb', line 704
def emit_buffered(tag, es)
@counters_monitor.synchronize{ @emit_count += 1 }
begin
execute_chunking(tag, es, enqueue: (@flush_mode == :immediate))
if !@retry && @buffer.queued?
submit_flush_once
end
rescue
@counters_monitor.synchronize{ @num_errors += 1 }
raise
end
end
|
#emit_events(tag, es) ⇒ Object
684
685
686
687
688
689
690
691
|
# File 'lib/fluent/plugin/output.rb', line 684
def emit_events(tag, es)
if @buffering
emit_buffered(tag, es)
else
emit_sync(tag, es)
end
end
|
#emit_sync(tag, es) ⇒ Object
693
694
695
696
697
698
699
700
701
702
|
# File 'lib/fluent/plugin/output.rb', line 693
def emit_sync(tag, es)
@counters_monitor.synchronize{ @emit_count += 1 }
begin
process(tag, es)
@counters_monitor.synchronize{ @emit_records += es.size }
rescue
@counters_monitor.synchronize{ @num_errors += 1 }
raise
end
end
|
#enqueue_thread_run ⇒ Object
1104
1105
1106
1107
1108
1109
1110
1111
1112
1113
1114
1115
1116
1117
1118
1119
1120
1121
1122
1123
1124
1125
1126
1127
1128
1129
1130
1131
1132
1133
1134
1135
1136
1137
1138
1139
1140
1141
1142
1143
1144
1145
1146
1147
1148
1149
1150
1151
1152
1153
1154
1155
1156
1157
1158
1159
1160
1161
1162
1163
1164
1165
1166
1167
|
# File 'lib/fluent/plugin/output.rb', line 1104
def enqueue_thread_run
value_for_interval = nil
if @flush_mode == :interval
value_for_interval = @buffer_config.flush_interval
end
if @chunk_key_time
if !value_for_interval || @buffer_config.timekey < value_for_interval
value_for_interval = @buffer_config.timekey
end
end
unless value_for_interval
raise "BUG: both of flush_interval and timekey are disabled"
end
interval = value_for_interval / 11.0
if interval < @buffer_config.flush_thread_interval
interval = @buffer_config.flush_thread_interval
end
while !self.after_started? && !self.stopped?
sleep 0.5
end
log.debug "enqueue_thread actually running"
begin
while @output_enqueue_thread_running
now_int = Time.now.to_i
if @output_flush_interrupted
sleep interval
next
end
@output_enqueue_thread_mutex.lock
begin
if @flush_mode == :interval
flush_interval = @buffer_config.flush_interval.to_i
@buffer.enqueue_all{ |metadata, chunk| chunk.created_at.to_i + flush_interval <= now_int }
end
if @chunk_key_time
timekey_unit = @buffer_config.timekey
timekey_wait = @buffer_config.timekey_wait
current_timekey = now_int - now_int % timekey_unit
@buffer.enqueue_all{ |metadata, chunk| metadata.timekey < current_timekey && metadata.timekey + timekey_unit + timekey_wait <= now_int }
end
rescue => e
raise if @under_plugin_development
log.error "unexpected error while checking flushed chunks. ignored.", plugin_id: plugin_id, error: e
log.error_backtrace
ensure
@output_enqueue_thread_waiting = false
@output_enqueue_thread_mutex.unlock
end
sleep interval
end
rescue => e
log.error "error on enqueue thread", plugin_id: plugin_id, error: e
log.error_backtrace
raise
end
end
|
#enqueue_thread_wait ⇒ Object
only for tests of output plugin
1085
1086
1087
1088
1089
1090
1091
1092
1093
1094
|
# File 'lib/fluent/plugin/output.rb', line 1085
def enqueue_thread_wait
@output_enqueue_thread_mutex.synchronize do
@output_flush_interrupted = false
@output_enqueue_thread_waiting = true
end
require 'timeout'
Timeout.timeout(10) do
Thread.pass while @output_enqueue_thread_waiting
end
end
|
#execute_chunking(tag, es, enqueue: false) ⇒ Object
768
769
770
771
772
773
774
775
776
|
# File 'lib/fluent/plugin/output.rb', line 768
def execute_chunking(tag, es, enqueue: false)
if @simple_chunking
handle_stream_simple(tag, es, enqueue: enqueue)
elsif @custom_format
handle_stream_with_custom_format(tag, es, enqueue: enqueue)
else
handle_stream_with_standard_format(tag, es, enqueue: enqueue)
end
end
|
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
|
# File 'lib/fluent/plugin/output.rb', line 643
def (str, metadata)
if metadata.empty?
str
else
rvalue = str.dup
if @chunk_key_time @output_time_formatter_cache[str] ||= Fluent::Timezone.formatter(@timekey_zone, str)
rvalue = @output_time_formatter_cache[str].call(metadata.timekey)
end
if @chunk_key_tag
if str.include?('${tag}')
rvalue = rvalue.gsub('${tag}', metadata.tag)
end
if str =~ CHUNK_TAG_PLACEHOLDER_PATTERN
hash = {}
metadata.tag.split('.').each_with_index do |part, i|
hash["${tag[#{i}]}"] = part
end
rvalue = rvalue.gsub(CHUNK_TAG_PLACEHOLDER_PATTERN, hash)
end
if rvalue =~ CHUNK_TAG_PLACEHOLDER_PATTERN
log.warn "tag placeholder '#{$1}' not replaced. tag:#{metadata.tag}, template:#{str}"
end
end
if !@chunk_keys.empty? && metadata.variables
hash = {'${tag}' => '${tag}'} @chunk_keys.each do |key|
hash["${#{key}}"] = metadata.variables[key.to_sym]
end
rvalue = rvalue.gsub(CHUNK_KEY_PLACEHOLDER_PATTERN, hash)
end
if rvalue =~ CHUNK_KEY_PLACEHOLDER_PATTERN
log.warn "chunk key placeholder '#{$1}' not replaced. templace:#{str}"
end
rvalue
end
end
|
#flush_thread_run(state) ⇒ Object
1169
1170
1171
1172
1173
1174
1175
1176
1177
1178
1179
1180
1181
1182
1183
1184
1185
1186
1187
1188
1189
1190
1191
1192
1193
1194
1195
1196
1197
1198
1199
1200
1201
1202
1203
1204
1205
1206
1207
1208
1209
1210
1211
|
# File 'lib/fluent/plugin/output.rb', line 1169
def flush_thread_run(state)
flush_thread_interval = @buffer_config.flush_thread_interval
clock_id = Process::CLOCK_MONOTONIC rescue Process::CLOCK_MONOTONIC_RAW
state.next_time = Process.clock_gettime(clock_id) + flush_thread_interval
while !self.after_started? && !self.stopped?
sleep 0.5
end
log.debug "flush_thread actually running"
begin
while @output_flush_threads_running
time = Process.clock_gettime(clock_id)
interval = state.next_time - time
if state.next_time <= time
try_flush
interval = next_flush_time.to_f - Time.now.to_f
state.next_time = Process.clock_gettime(clock_id) + interval
end
if @dequeued_chunks_mutex.synchronize{ !@dequeued_chunks.empty? && @dequeued_chunks.first.expired? }
unless @output_flush_interrupted
try_rollback_write
end
end
sleep interval if interval > 0
end
rescue => e
log.error "error on output thread", plugin_id: plugin_id, error_class: e.class, error: e
log.error_backtrace
raise
end
end
|
#flush_thread_wakeup ⇒ Object
only for tests of output plugin
1097
1098
1099
1100
1101
1102
|
# File 'lib/fluent/plugin/output.rb', line 1097
def flush_thread_wakeup
@output_flush_threads.each do |state|
state.next_time = 0
state.thread.run
end
end
|
#force_flush ⇒ Object
1065
1066
1067
1068
1069
1070
|
# File 'lib/fluent/plugin/output.rb', line 1065
def force_flush
if @buffering
@buffer.enqueue_all
submit_flush_all
end
end
|
117
118
119
120
|
# File 'lib/fluent/plugin/output.rb', line 117
def format(tag, time, record)
raise NotImplementedError, "BUG: output plugins MUST implement this method"
end
|
122
123
124
125
126
|
# File 'lib/fluent/plugin/output.rb', line 122
def formatted_to_msgpack_binary
false
end
|
#get_placeholders_keys(str) ⇒ Object
638
639
640
|
# File 'lib/fluent/plugin/output.rb', line 638
def get_placeholders_keys(str)
str.scan(CHUNK_KEY_PLACEHOLDER_PATTERN).map{|ph| ph[2..-2]}.reject{|s| s == "tag"}.sort
end
|
#get_placeholders_tag(str) ⇒ Object
625
626
627
628
629
630
631
632
633
634
635
636
|
# File 'lib/fluent/plugin/output.rb', line 625
def get_placeholders_tag(str)
parts = []
str.scan(CHUNK_TAG_PLACEHOLDER_PATTERN).map(&:first).each do |ph|
if ph == "tag"
parts << -1
elsif ph =~ /^tag\[(\d+)\]$/
parts << $1.to_i
end
end
parts.sort
end
|
#get_placeholders_time(str) ⇒ Object
it’s not validated to use timekey larger than 1 day
#handle_stream_simple(tag, es, enqueue: false) ⇒ Object
868
869
870
871
872
873
874
875
876
877
878
879
880
881
882
883
884
885
886
887
888
|
# File 'lib/fluent/plugin/output.rb', line 868
def handle_stream_simple(tag, es, enqueue: false)
format_proc = nil
meta = metadata((@chunk_key_tag ? tag : nil), nil, nil)
records = es.size
if @custom_format
records = 0
data = []
es.each do |time, record|
data << format(tag, time, record)
records += 1
end
else
format_proc = generate_format_proc
data = es
end
write_guard do
@buffer.write({meta => data}, format: format_proc, enqueue: enqueue)
end
@counters_monitor.synchronize{ @emit_records += records }
true
end
|
metadata_and_data is a Hash of:
(standard format) metadata => event stream
(custom format) metadata => array of formatted event
For standard format, formatting should be done for whole event stream, but
"whole event stream" may be a split of "es" here when it's bigger than chunk_limit_size.
`@buffer.write` will do this splitting.
For custom format, formatting will be done here. Custom formatting always requires
iteration of event stream, and it should be done just once even if total event stream size
is bigger than chunk_limit_size because of performance.
835
836
837
838
839
840
841
842
843
844
845
846
847
848
849
|
# File 'lib/fluent/plugin/output.rb', line 835
def handle_stream_with_custom_format(tag, es, enqueue: false)
meta_and_data = {}
records = 0
es.each do |time, record|
meta = metadata(tag, time, record)
meta_and_data[meta] ||= []
meta_and_data[meta] << format(tag, time, record)
records += 1
end
write_guard do
@buffer.write(meta_and_data, enqueue: enqueue)
end
@counters_monitor.synchronize{ @emit_records += records }
true
end
|
851
852
853
854
855
856
857
858
859
860
861
862
863
864
865
866
|
# File 'lib/fluent/plugin/output.rb', line 851
def handle_stream_with_standard_format(tag, es, enqueue: false)
format_proc = generate_format_proc
meta_and_data = {}
records = 0
es.each do |time, record|
meta = metadata(tag, time, record)
meta_and_data[meta] ||= MultiEventStream.new
meta_and_data[meta].add(time, record)
records += 1
end
write_guard do
@buffer.write(meta_and_data, format: format_proc, enqueue: enqueue)
end
@counters_monitor.synchronize{ @emit_records += records }
true
end
|
#implement?(feature) ⇒ Boolean
496
497
498
499
500
501
502
503
504
505
506
|
# File 'lib/fluent/plugin/output.rb', line 496
def implement?(feature)
methods_of_plugin = self.class.instance_methods(false)
case feature
when :synchronous then methods_of_plugin.include?(:process) || support_in_v12_style?(:synchronous)
when :buffered then methods_of_plugin.include?(:write) || support_in_v12_style?(:buffered)
when :delayed_commit then methods_of_plugin.include?(:try_write)
when :custom_format then methods_of_plugin.include?(:format) || support_in_v12_style?(:custom_format)
else
raise ArgumentError, "Unknown feature for output plugin: #{feature}"
end
end
|
#interrupt_flushes ⇒ Object
only for tests of output plugin
1080
1081
1082
|
# File 'lib/fluent/plugin/output.rb', line 1080
def interrupt_flushes
@output_flush_interrupted = true
end
|
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
734
735
736
737
738
739
740
741
742
743
744
745
746
747
748
749
750
751
752
753
754
755
756
757
758
759
|
# File 'lib/fluent/plugin/output.rb', line 719
def metadata(tag, time, record)
raise ArgumentError, "tag must be a String: #{tag.class}" unless tag.nil? || tag.is_a?(String)
raise ArgumentError, "time must be a Fluent::EventTime (or Integer): #{time.class}" unless time.nil? || time.is_a?(Fluent::EventTime) || time.is_a?(Integer)
raise ArgumentError, "record must be a Hash: #{record.class}" unless record.nil? || record.is_a?(Hash)
if @chunk_keys.nil? && @chunk_key_time.nil? && @chunk_key_tag.nil?
return Struct.new(:timekey, :tag, :variables).new
end
if @chunk_keys.empty?
if !@chunk_key_time && !@chunk_key_tag
@buffer.metadata()
elsif @chunk_key_time && @chunk_key_tag
time_int = time.to_i
timekey = (time_int - (time_int % @buffer_config.timekey)).to_i
@buffer.metadata(timekey: timekey, tag: tag)
elsif @chunk_key_time
time_int = time.to_i
timekey = (time_int - (time_int % @buffer_config.timekey)).to_i
@buffer.metadata(timekey: timekey)
else
@buffer.metadata(tag: tag)
end
else
timekey = if @chunk_key_time
time_int = time.to_i
(time_int - (time_int % @buffer_config.timekey)).to_i
else
nil
end
pairs = Hash[@chunk_keys.map{|k| [k.to_sym, record[k]]}]
@buffer.metadata(timekey: timekey, tag: (@chunk_key_tag ? tag : nil), variables: pairs)
end
end
|
761
762
763
764
765
766
|
# File 'lib/fluent/plugin/output.rb', line 761
def metadata_for_test(tag, time, record)
raise "BUG: #metadata_for_test is available only when no actual metadata exists" unless @buffer.metadata_list.empty?
m = metadata(tag, time, record)
@buffer.metadata_list_clear!
m
end
|
#next_flush_time ⇒ Object
953
954
955
956
957
958
959
960
961
|
# File 'lib/fluent/plugin/output.rb', line 953
def next_flush_time
if @buffer.queued?
@retry_mutex.synchronize do
@retry ? @retry.next_time : Time.now + @buffer_config.flush_thread_burst_interval
end
else
Time.now + @buffer_config.flush_thread_interval
end
end
|
#placeholder_validate!(name, str) ⇒ Object
508
509
510
511
512
|
# File 'lib/fluent/plugin/output.rb', line 508
def placeholder_validate!(name, str)
placeholder_validators(name, str).each do |v|
v.validate!
end
end
|
#placeholder_validators(name, str, time_key = (@chunk_key_time && @buffer_config.timekey), tag_key = @chunk_key_tag, chunk_keys = @chunk_keys) ⇒ Object
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
|
# File 'lib/fluent/plugin/output.rb', line 514
def placeholder_validators(name, str, time_key = (@chunk_key_time && @buffer_config.timekey), tag_key = @chunk_key_tag, chunk_keys = @chunk_keys)
validators = []
sec, title, example = get_placeholders_time(str)
if sec || time_key
validators << PlaceholderValidator.new(name, str, :time, {sec: sec, title: title, example: example, timekey: time_key})
end
parts = get_placeholders_tag(str)
if tag_key || !parts.empty?
validators << PlaceholderValidator.new(name, str, :tag, {parts: parts, tagkey: tag_key})
end
keys = get_placeholders_keys(str)
if chunk_keys && !chunk_keys.empty? || !keys.empty?
validators << PlaceholderValidator.new(name, str, :keys, {keys: keys, chunkkeys: chunk_keys})
end
validators
end
|
#prefer_buffered_processing ⇒ Object
128
129
130
131
132
133
|
# File 'lib/fluent/plugin/output.rb', line 128
def prefer_buffered_processing
true
end
|
#prefer_delayed_commit ⇒ Object
135
136
137
138
|
# File 'lib/fluent/plugin/output.rb', line 135
def prefer_delayed_commit
true
end
|
#process(tag, es) ⇒ Object
105
106
107
|
# File 'lib/fluent/plugin/output.rb', line 105
def process(tag, es)
raise NotImplementedError, "BUG: output plugins MUST implement this method"
end
|
#retry_state(randomize) ⇒ Object
1038
1039
1040
1041
1042
1043
1044
1045
1046
1047
1048
1049
1050
1051
1052
1053
1054
1055
|
# File 'lib/fluent/plugin/output.rb', line 1038
def retry_state(randomize)
if @secondary
retry_state_create(
:output_retries, @buffer_config.retry_type, @buffer_config.retry_wait, @buffer_config.retry_timeout,
forever: @buffer_config.retry_forever, max_steps: @buffer_config.retry_max_times, backoff_base: @buffer_config.retry_exponential_backoff_base,
max_interval: @buffer_config.retry_max_interval,
secondary: true, secondary_threshold: @buffer_config.retry_secondary_threshold,
randomize: randomize
)
else
retry_state_create(
:output_retries, @buffer_config.retry_type, @buffer_config.retry_wait, @buffer_config.retry_timeout,
forever: @buffer_config.retry_forever, max_steps: @buffer_config.retry_max_times, backoff_base: @buffer_config.retry_exponential_backoff_base,
max_interval: @buffer_config.retry_max_interval,
randomize: randomize
)
end
end
|
#rollback_write(chunk_id) ⇒ Object
911
912
913
914
915
916
917
918
919
920
921
922
923
924
925
926
|
# File 'lib/fluent/plugin/output.rb', line 911
def rollback_write(chunk_id)
@dequeued_chunks_mutex.synchronize do
@dequeued_chunks.delete_if{ |info| info.chunk_id == chunk_id }
end
if @buffer.takeback_chunk(chunk_id)
@counters_monitor.synchronize{ @rollback_count += 1 }
true
else
false
end
end
|
#shutdown ⇒ Object
442
443
444
445
446
447
|
# File 'lib/fluent/plugin/output.rb', line 442
def shutdown
@secondary.shutdown if @secondary
@buffer.shutdown if @buffering && @buffer
super
end
|
#start ⇒ Object
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
|
# File 'lib/fluent/plugin/output.rb', line 331
def start
super
if @buffering.nil?
@buffering = prefer_buffered_processing
if !@buffering && @buffer
@buffer.terminate @buffer = nil
end
end
if @buffering
m = method(:emit_buffered)
(class << self; self; end).module_eval do
define_method(:emit_events, m)
end
@custom_format = implement?(:custom_format)
@enable_msgpack_streamer = @custom_format ? formatted_to_msgpack_binary : true
@delayed_commit = if implement?(:buffered) && implement?(:delayed_commit)
prefer_delayed_commit
else
implement?(:delayed_commit)
end
@delayed_commit_timeout = @buffer_config.delayed_commit_timeout
else m = method(:emit_sync)
(class << self; self; end).module_eval do
define_method(:emit_events, m)
end
end
if @buffering && !@as_secondary
@retry = nil
@retry_mutex = Mutex.new
@buffer.start
@output_enqueue_thread = nil
@output_enqueue_thread_running = true
@output_flush_threads = []
@output_flush_threads_mutex = Mutex.new
@output_flush_threads_running = true
@output_flush_interrupted = false
@output_enqueue_thread_mutex = Mutex.new
@output_enqueue_thread_waiting = false
@dequeued_chunks = []
@dequeued_chunks_mutex = Mutex.new
@buffer_config.flush_thread_count.times do |i|
thread_title = "flush_thread_#{i}".to_sym
thread_state = FlushThreadState.new(nil, nil)
thread = thread_create(thread_title) do
flush_thread_run(thread_state)
end
thread_state.thread = thread
@output_flush_threads_mutex.synchronize do
@output_flush_threads << thread_state
end
end
@output_flush_thread_current_position = 0
unless @in_tests
if @flush_mode == :interval || @chunk_key_time
@output_enqueue_thread = thread_create(:enqueue_thread, &method(:enqueue_thread_run))
end
end
end
@secondary.start if @secondary
end
|
#stop ⇒ Object
416
417
418
419
420
421
|
# File 'lib/fluent/plugin/output.rb', line 416
def stop
@secondary.stop if @secondary
@buffer.stop if @buffering && @buffer
super
end
|
#submit_flush_all ⇒ Object
1072
1073
1074
1075
1076
1077
|
# File 'lib/fluent/plugin/output.rb', line 1072
def submit_flush_all
while !@retry && @buffer.queued?
submit_flush_once
sleep @buffer_config.flush_thread_burst_interval
end
end
|
#submit_flush_once ⇒ Object
1057
1058
1059
1060
1061
1062
1063
|
# File 'lib/fluent/plugin/output.rb', line 1057
def submit_flush_once
@output_flush_thread_current_position = (@output_flush_thread_current_position + 1) % @buffer_config.flush_thread_count
state = @output_flush_threads[@output_flush_thread_current_position]
state.next_time = 0
state.thread.run
end
|
#support_in_v12_style?(feature) ⇒ Boolean
484
485
486
487
488
489
490
491
492
493
494
|
# File 'lib/fluent/plugin/output.rb', line 484
def support_in_v12_style?(feature)
case feature
when :synchronous then false
when :buffered then false
when :delayed_commit then false
when :custom_format then false
else
raise ArgumentError, "unknown feature: #{feature}"
end
end
|
#terminate ⇒ Object
477
478
479
480
481
482
|
# File 'lib/fluent/plugin/output.rb', line 477
def terminate
@buffer.terminate if @buffering && @buffer
@secondary.terminate if @secondary
super
end
|
#try_flush ⇒ Object
963
964
965
966
967
968
969
970
971
972
973
974
975
976
977
978
979
980
981
982
983
984
985
986
987
988
989
990
991
992
993
994
995
996
997
998
999
1000
1001
1002
1003
1004
1005
1006
1007
1008
1009
1010
1011
1012
1013
1014
1015
1016
1017
1018
1019
1020
1021
1022
1023
1024
1025
1026
1027
1028
1029
1030
1031
1032
1033
1034
1035
1036
|
# File 'lib/fluent/plugin/output.rb', line 963
def try_flush
chunk = @buffer.dequeue_chunk
return unless chunk
log.debug "trying flush for a chunk", chunk: dump_unique_id_hex(chunk.unique_id)
output = self
using_secondary = false
if @retry_mutex.synchronize{ @retry && @retry.secondary? }
output = @secondary
using_secondary = true
end
if @enable_msgpack_streamer
chunk.extend ChunkMessagePackEventStreamer
end
begin
if output.delayed_commit
log.trace "executing delayed write and commit", chunk: dump_unique_id_hex(chunk.unique_id)
@counters_monitor.synchronize{ @write_count += 1 }
output.try_write(chunk)
@dequeued_chunks_mutex.synchronize do
@dequeued_chunks << DequeuedChunkInfo.new(chunk.unique_id, Time.now, self.delayed_commit_timeout)
end
else chunk_id = chunk.unique_id
dump_chunk_id = dump_unique_id_hex(chunk_id)
log.trace "adding write count", instance: self.object_id
@counters_monitor.synchronize{ @write_count += 1 }
log.trace "executing sync write", chunk: dump_chunk_id
output.write(chunk)
log.trace "write operation done, committing", chunk: dump_chunk_id
commit_write(chunk_id, secondary: using_secondary)
log.trace "done to commit a chunk", chunk: dump_chunk_id
end
rescue => e
log.debug "taking back chunk for errors.", plugin_id: plugin_id, chunk: dump_unique_id_hex(chunk.unique_id)
@buffer.takeback_chunk(chunk.unique_id)
if @under_plugin_development
raise
end
@retry_mutex.synchronize do
if @retry
@counters_monitor.synchronize{ @num_errors += 1 }
if @retry.limit?
records = @buffer.queued_records
log.error "failed to flush the buffer, and hit limit for retries. dropping all chunks in the buffer queue.", plugin_id: plugin_id, retry_times: @retry.steps, records: records, error: e
log.error_backtrace e.backtrace
@buffer.clear_queue!
log.debug "buffer queue cleared", plugin_id: plugin_id
@retry = nil
else
@retry.step
msg = if using_secondary
"failed to flush the buffer with secondary output."
else
"failed to flush the buffer."
end
log.warn msg, plugin_id: plugin_id, retry_time: @retry.steps, next_retry: @retry.next_time, chunk: dump_unique_id_hex(chunk.unique_id), error: e
log.warn_backtrace e.backtrace
end
else
@retry = retry_state(@buffer_config.retry_randomize)
@counters_monitor.synchronize{ @num_errors += 1 }
log.warn "failed to flush the buffer.", plugin_id: plugin_id, retry_time: @retry.steps, next_retry: @retry.next_time, chunk: dump_unique_id_hex(chunk.unique_id), error: e
log.warn_backtrace e.backtrace
end
end
end
end
|
#try_rollback_all ⇒ Object
940
941
942
943
944
945
946
947
948
949
950
951
|
# File 'lib/fluent/plugin/output.rb', line 940
def try_rollback_all
return unless @dequeued_chunks
@dequeued_chunks_mutex.synchronize do
until @dequeued_chunks.empty?
info = @dequeued_chunks.shift
if @buffer.takeback_chunk(info.chunk_id)
@counters_monitor.synchronize{ @rollback_count += 1 }
log.info "delayed commit for buffer chunks was cancelled in shutdown", plugin_id: plugin_id, chunk_id: dump_unique_id_hex(info.chunk_id)
end
end
end
end
|
#try_rollback_write ⇒ Object
928
929
930
931
932
933
934
935
936
937
938
|
# File 'lib/fluent/plugin/output.rb', line 928
def try_rollback_write
@dequeued_chunks_mutex.synchronize do
while @dequeued_chunks.first && @dequeued_chunks.first.expired?
info = @dequeued_chunks.shift
if @buffer.takeback_chunk(info.chunk_id)
@counters_monitor.synchronize{ @rollback_count += 1 }
log.warn "failed to flush the buffer chunk, timeout to commit.", plugin_id: plugin_id, chunk_id: dump_unique_id_hex(info.chunk_id), flushed_at: info.time
end
end
end
end
|
#try_write(chunk) ⇒ Object
113
114
115
|
# File 'lib/fluent/plugin/output.rb', line 113
def try_write(chunk)
raise NotImplementedError, "BUG: output plugins MUST implement this method"
end
|
#write(chunk) ⇒ Object
109
110
111
|
# File 'lib/fluent/plugin/output.rb', line 109
def write(chunk)
raise NotImplementedError, "BUG: output plugins MUST implement this method"
end
|
#write_guard(&block) ⇒ Object
778
779
780
781
782
783
784
785
786
787
788
789
790
791
792
793
794
795
796
797
798
799
800
801
802
803
804
805
806
807
808
809
810
811
|
# File 'lib/fluent/plugin/output.rb', line 778
def write_guard(&block)
begin
block.call
rescue Fluent::Plugin::Buffer::BufferOverflowError
log.warn "failed to write data into buffer by buffer overflow"
case @buffer_config.overflow_action
when :throw_exception
raise
when :block
log.debug "buffer.write is now blocking"
until @buffer.storable?
sleep 1
end
log.debug "retrying buffer.write after blocked operation"
retry
when :drop_oldest_chunk
begin
oldest = @buffer.dequeue_chunk
if oldest
log.warn "dropping oldest chunk to make space after buffer overflow", chunk_id: oldest.unique_id
@buffer.purge_chunk(oldest.unique_id)
else
log.error "no queued chunks to be dropped for drop_oldest_chunk"
end
rescue
end
raise unless @buffer.storable?
retry
else
raise "BUG: unknown overflow_action '#{@buffer_config.overflow_action}'"
end
end
end
|