Class: LogStash::Pipeline

Inherits:
Object
  • Object
show all
Includes:
Util::Loggable
Defined in:
lib/logstash/pipeline.rb

Constant Summary collapse

MAX_INFLIGHT_WARN_THRESHOLD =
10_000
RELOAD_INCOMPATIBLE_PLUGINS =
[
  "LogStash::Inputs::Stdin"
]

Instance Attribute Summary collapse

Instance Method Summary collapse

Methods included from Util::Loggable

included, #logger

Constructor Details

#initialize(config_str, settings = SETTINGS, namespaced_metric = nil) ⇒ Pipeline

Returns a new instance of Pipeline.



48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
# File 'lib/logstash/pipeline.rb', line 48

def initialize(config_str, settings = SETTINGS, namespaced_metric = nil)
  @logger = self.logger
  @config_str = config_str
  @config_hash = Digest::SHA1.hexdigest(@config_str)
  # Every time #plugin is invoked this is incremented to give each plugin
  # a unique id when auto-generating plugin ids
  @plugin_counter ||= 0
  @settings = settings
  @pipeline_id = @settings.get_value("pipeline.id") || self.object_id
  @reporter = PipelineReporter.new(@logger, self)

  # A list of plugins indexed by id
  @plugins_by_id = {}
  @inputs = nil
  @filters = nil
  @outputs = nil

  @worker_threads = []

  # This needs to be configured before we evaluate the code to make
  # sure the metric instance is correctly send to the plugins to make the namespace scoping work
  @metric = namespaced_metric.nil? ? Instrument::NullMetric.new : namespaced_metric

  grammar = LogStashConfigParser.new
  @config = grammar.parse(config_str)
  if @config.nil?
    raise ConfigurationError, grammar.failure_reason
  end
  # This will compile the config to ruby and evaluate the resulting code.
  # The code will initialize all the plugins and define the
  # filter and output methods.
  code = @config.compile
  @code = code

  # The config code is hard to represent as a log message...
  # So just print it.

  if @settings.get_value("config.debug") && @logger.debug?
    @logger.debug("Compiled pipeline code", :code => code)
  end

  begin
    eval(code)
  rescue => e
    raise
  end

  queue = Util::WrappedSynchronousQueue.new
  @input_queue_client = queue.write_client
  @filter_queue_client = queue.read_client
  # Note that @inflight_batches as a central mechanism for tracking inflight
  # batches will fail if we have multiple read clients here.
  @filter_queue_client.set_events_metric(metric.namespace([:stats, :events]))
  @filter_queue_client.set_pipeline_metric(
      metric.namespace([:stats, :pipelines, pipeline_id.to_s.to_sym, :events])
  )
  @events_filtered = Concurrent::AtomicFixnum.new(0)
  @events_consumed = Concurrent::AtomicFixnum.new(0)

  @input_threads = []
  # @ready requires thread safety since it is typically polled from outside the pipeline thread
  @ready = Concurrent::AtomicBoolean.new(false)
  @running = Concurrent::AtomicBoolean.new(false)
  @flushing = Concurrent::AtomicReference.new(false)
end

Instance Attribute Details

#config_hashObject (readonly)

Returns the value of attribute config_hash.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def config_hash
  @config_hash
end

#config_strObject (readonly)

Returns the value of attribute config_str.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def config_str
  @config_str
end

#events_consumedObject (readonly)

Returns the value of attribute events_consumed.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def events_consumed
  @events_consumed
end

#events_filteredObject (readonly)

Returns the value of attribute events_filtered.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def events_filtered
  @events_filtered
end

#filter_queue_clientObject (readonly)

Returns the value of attribute filter_queue_client.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def filter_queue_client
  @filter_queue_client
end

#filtersObject (readonly)

Returns the value of attribute filters.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def filters
  @filters
end

#input_queue_clientObject (readonly)

Returns the value of attribute input_queue_client.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def input_queue_client
  @input_queue_client
end

#inputsObject (readonly)

Returns the value of attribute inputs.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def inputs
  @inputs
end

#metricObject (readonly)

Returns the value of attribute metric.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def metric
  @metric
end

#outputsObject (readonly)

Returns the value of attribute outputs.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def outputs
  @outputs
end

#pipeline_idObject (readonly)

Returns the value of attribute pipeline_id.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def pipeline_id
  @pipeline_id
end

#reporterObject (readonly)

Returns the value of attribute reporter.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def reporter
  @reporter
end

#settingsObject (readonly)

Returns the value of attribute settings.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def settings
  @settings
end

#started_atObject (readonly)

Returns the value of attribute started_at.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def started_at
  @started_at
end

#threadObject (readonly)

Returns the value of attribute thread.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def thread
  @thread
end

#worker_threadsObject (readonly)

Returns the value of attribute worker_threads.



25
26
27
# File 'lib/logstash/pipeline.rb', line 25

def worker_threads
  @worker_threads
end

Instance Method Details

#filter(event, &block) ⇒ Object

for backward compatibility in devutils for the rspec helpers, this method is not used in the pipeline anymore.



434
435
436
437
# File 'lib/logstash/pipeline.rb', line 434

def filter(event, &block)
  # filter_func returns all filtered events, including cancelled ones
  filter_func(event).each { |e| block.call(e) }
end

#filter_batch(batch) ⇒ Object



257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
# File 'lib/logstash/pipeline.rb', line 257

def filter_batch(batch)
  batch.each do |event|
    if event.is_a?(Event)
      filter_func(event).each do |e|
        # these are both original and generated events
        batch.merge(e) unless e.cancelled?
      end
    end
  end
  @filter_queue_client.add_filtered_metrics(batch)
  @events_filtered.increment(batch.size)
rescue Exception => e
  # Plugins authors should manage their own exceptions in the plugin code
  # but if an exception is raised up to the worker thread they are considered
  # fatal and logstash will not recover from this situation.
  #
  # Users need to check their configuration or see if there is a bug in the
  # plugin.
  @logger.error("Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash.",
                "exception" => e, "backtrace" => e.backtrace)
  raise
end

#filters?Boolean

Returns:

  • (Boolean)


143
144
145
# File 'lib/logstash/pipeline.rb', line 143

def filters?
  return @filters.any?
end

#flushObject



467
468
469
470
471
472
# File 'lib/logstash/pipeline.rb', line 467

def flush
  if @flushing.compare_and_set(false, true)
    @logger.debug? && @logger.debug("Pushing flush onto pipeline")
    @input_queue_client.push(FLUSH)
  end
end

#flush_filters(options = {}, &block) ⇒ Object

perform filters flush and yield flushed event to the passed block

Parameters:

  • options (Hash) (defaults to: {})

Options Hash (options):

  • :final (Boolean)

    > true to signal a final shutdown flush



443
444
445
446
447
448
449
# File 'lib/logstash/pipeline.rb', line 443

def flush_filters(options = {}, &block)
  flushers = options[:final] ? @shutdown_flushers : @periodic_flushers

  flushers.each do |flusher|
    flusher.call(options, &block)
  end
end

#flush_filters_to_batch(batch, options = {}) ⇒ Object

perform filters flush into the output queue

Parameters:

  • batch (ReadClient::ReadBatch)
  • options (Hash) (defaults to: {})


487
488
489
490
491
492
493
494
495
496
497
# File 'lib/logstash/pipeline.rb', line 487

def flush_filters_to_batch(batch, options = {})
  options[:final] = batch.shutdown_signal_received?
  flush_filters(options) do |event|
    unless event.cancelled?
      @logger.debug? and @logger.debug("Pushing flushed events", :event => event)
      batch.merge(event)
    end
  end

  @flushing.set(false)
end

#inputworker(plugin) ⇒ Object



328
329
330
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
# File 'lib/logstash/pipeline.rb', line 328

def inputworker(plugin)
  Util::set_thread_name("[#{pipeline_id}]<#{plugin.class.config_name}")
  begin
    plugin.run(@input_queue_client)
  rescue => e
    if plugin.stop?
      @logger.debug("Input plugin raised exception during shutdown, ignoring it.",
                    :plugin => plugin.class.config_name, :exception => e,
                    :backtrace => e.backtrace)
      return
    end

    # otherwise, report error and restart
    if @logger.debug?
      @logger.error(I18n.t("logstash.pipeline.worker-error-debug",
                           :plugin => plugin.inspect, :error => e.to_s,
                           :exception => e.class,
                           :stacktrace => e.backtrace.join("\n")))
    else
      @logger.error(I18n.t("logstash.pipeline.worker-error",
                           :plugin => plugin.inspect, :error => e))
    end

    # Assuming the failure that caused this exception is transient,
    # let's sleep for a bit and execute #run again
    sleep(1)
    retry
  ensure
    plugin.do_close
  end
end

#inspectObject

Sometimes we log stuff that will dump the pipeline which may contain sensitive information (like the raw syntax tree which can contain passwords) We want to hide most of what’s in here



522
523
524
525
526
527
528
529
530
# File 'lib/logstash/pipeline.rb', line 522

def inspect
  {
    :pipeline_id => @pipeline_id,
    :settings => @settings.inspect,
    :ready => @ready,
    :running => @running,
    :flushing => @flushing
  }
end

#non_reloadable_pluginsObject



513
514
515
516
517
# File 'lib/logstash/pipeline.rb', line 513

def non_reloadable_plugins
  (inputs + filters + outputs).select do |plugin|
    RELOAD_INCOMPATIBLE_PLUGINS.include?(plugin.class.name)
  end
end

#output_batch(batch) ⇒ Object

Take an array of events and send them to the correct output



281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
# File 'lib/logstash/pipeline.rb', line 281

def output_batch(batch)
  # Build a mapping of { output_plugin => [events...]}
  output_events_map = Hash.new { |h, k| h[k] = [] }
  batch.each do |event|
    # We ask the AST to tell us which outputs to send each event to
    # Then, we stick it in the correct bin

    # output_func should never return anything other than an Array but we have lots of legacy specs
    # that monkeypatch it and return nil. We can deprecate  "|| []" after fixing these specs
    (output_func(event) || []).each do |output|
      output_events_map[output].push(event)
    end
  end
  # Now that we have our output to event mapping we can just invoke each output
  # once with its list of events
  output_events_map.each do |output, events|
    output.multi_receive(events)
  end
  
  @filter_queue_client.add_output_metrics(batch)
end

#plugin(plugin_type, name, *args) ⇒ Object

Raises:



397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
# File 'lib/logstash/pipeline.rb', line 397

def plugin(plugin_type, name, *args)
  @plugin_counter += 1

  # Collapse the array of arguments into a single merged hash
  args = args.reduce({}, &:merge)

  id = if args["id"].nil? || args["id"].empty?
         args["id"] = "#{@config_hash}-#{@plugin_counter}"
       else
         args["id"]
       end

  raise ConfigurationError, "Two plugins have the id '#{id}', please fix this conflict" if @plugins_by_id[id]
  
  pipeline_scoped_metric = metric.namespace([:stats, :pipelines, pipeline_id.to_s.to_sym, :plugins])

  klass = Plugin.lookup(plugin_type, name)

  # Scope plugins of type 'input' to 'inputs'
  type_scoped_metric = pipeline_scoped_metric.namespace("#{plugin_type}s".to_sym)
  plugin = if plugin_type == "output"
             OutputDelegator.new(@logger, klass, type_scoped_metric,
                                 OutputDelegatorStrategyRegistry.instance,
                                 args)
           elsif plugin_type == "filter"
             FilterDelegator.new(@logger, klass, type_scoped_metric, args)
           else # input
             input_plugin = klass.new(args)
             input_plugin.metric = type_scoped_metric.namespace(id)
             input_plugin
           end
  
  @plugins_by_id[id] = plugin
end

#plugin_threads_infoObject

flush_filters_to_batch



499
500
501
502
503
# File 'lib/logstash/pipeline.rb', line 499

def plugin_threads_info
  input_threads = @input_threads.select {|t| t.alive? }
  worker_threads = @worker_threads.select {|t| t.alive? }
  (input_threads + worker_threads).map {|t| Util.thread_info(t) }
end

#ready?Boolean

def initialize

Returns:

  • (Boolean)


114
115
116
# File 'lib/logstash/pipeline.rb', line 114

def ready?
  @ready.value
end

#runObject



147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
# File 'lib/logstash/pipeline.rb', line 147

def run
  @started_at = Time.now

  @thread = Thread.current
  Util.set_thread_name("[#{pipeline_id}]-pipeline-manager")

  start_workers

  @logger.info("Pipeline #{@pipeline_id} started")

  # Block until all inputs have stopped
  # Generally this happens if SIGINT is sent and `shutdown` is called from an external thread

  transition_to_running
  start_flusher # Launches a non-blocking thread for flush events
  wait_inputs
  transition_to_stopped

  @logger.debug("Input plugins stopped! Will shutdown filter/output workers.")

  shutdown_flusher
  shutdown_workers

  @logger.debug("Pipeline #{@pipeline_id} has been shutdown")

  # exit code
  return 0
end

#running?Boolean

Returns:

  • (Boolean)


184
185
186
# File 'lib/logstash/pipeline.rb', line 184

def running?
  @running.true?
end

#safe_pipeline_worker_countObject



118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
# File 'lib/logstash/pipeline.rb', line 118

def safe_pipeline_worker_count
  default = @settings.get_default("pipeline.workers")
  pipeline_workers = @settings.get("pipeline.workers") #override from args "-w 8" or config
  safe_filters, unsafe_filters = @filters.partition(&:threadsafe?)
  plugins = unsafe_filters.collect { |f| f.config_name }

  return pipeline_workers if unsafe_filters.empty?

  if @settings.set?("pipeline.workers")
    if pipeline_workers > 1
      @logger.warn("Warning: Manual override - there are filters that might not work with multiple worker threads",
                   :worker_threads => pipeline_workers, :filters => plugins)
    end
  else
    # user did not specify a worker thread count
    # warn if the default is multiple
    if default > 1
      @logger.warn("Defaulting pipeline worker threads to 1 because there are some filters that might not work with multiple worker threads",
                   :count_was => default, :filters => plugins)
      return 1 # can't allow the default value to propagate if there are unsafe filters
    end
  end
  pipeline_workers
end

#shutdown(&before_stop) ⇒ Object

initiate the pipeline shutdown sequence this method is intended to be called from outside the pipeline thread

Parameters:

  • before_stop (Proc)

    code block called before performing stop operation on input plugins



363
364
365
366
367
368
369
370
371
372
373
374
375
376
# File 'lib/logstash/pipeline.rb', line 363

def shutdown(&before_stop)
  # shutdown can only start once the pipeline has completed its startup.
  # avoid potential race conditoon between the startup sequence and this
  # shutdown method which can be called from another thread at any time
  sleep(0.1) while !ready?

  # TODO: should we also check against calling shutdown multiple times concurently?

  before_stop.call if block_given?

  @logger.debug "Closing inputs"
  @inputs.each(&:do_stop)
  @logger.debug "Closed inputs"
end

#shutdown_flusherObject



463
464
465
# File 'lib/logstash/pipeline.rb', line 463

def shutdown_flusher
  @flusher_thread.join
end

#shutdown_workersObject

After ‘shutdown` is called from an external thread this is called from the main thread to tell the worker threads to stop and then block until they’ve fully stopped This also stops all filter and output plugins



381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
# File 'lib/logstash/pipeline.rb', line 381

def shutdown_workers
  # Each worker thread will receive this exactly once!
  @worker_threads.each do |t|
    @logger.debug("Pushing shutdown", :thread => t.inspect)
    @input_queue_client.push(SHUTDOWN)
  end

  @worker_threads.each do |t|
    @logger.debug("Shutdown waiting for worker thread #{t}")
    t.join
  end

  @filters.each(&:do_close)
  @outputs.each(&:do_close)
end

#stalling_threads_infoObject



505
506
507
508
509
510
511
# File 'lib/logstash/pipeline.rb', line 505

def stalling_threads_info
  plugin_threads_info
    .reject {|t| t["blocked_on"] } # known benign blocking statuses
    .each {|t| t.delete("backtrace") }
    .each {|t| t.delete("blocked_on") }
    .each {|t| t.delete("status") }
end

#start_flusherObject



451
452
453
454
455
456
457
458
459
460
461
# File 'lib/logstash/pipeline.rb', line 451

def start_flusher
  # Invariant to help detect improper initialization
  raise "Attempted to start flusher on a stopped pipeline!" if stopped?

  @flusher_thread = Thread.new do
    while Stud.stoppable_sleep(5, 0.1) { stopped? }
      flush
      break if stopped?
    end
  end
end

#start_input(plugin) ⇒ Object



324
325
326
# File 'lib/logstash/pipeline.rb', line 324

def start_input(plugin)
  @input_threads << Thread.new { inputworker(plugin) }
end

#start_inputsObject



307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
# File 'lib/logstash/pipeline.rb', line 307

def start_inputs
  moreinputs = []
  @inputs.each do |input|
    if input.threadable && input.threads > 1
      (input.threads - 1).times do |i|
        moreinputs << input.clone
      end
    end
  end
  @inputs += moreinputs

  @inputs.each do |input|
    input.register
    start_input(input)
  end
end

#start_workersObject



192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
# File 'lib/logstash/pipeline.rb', line 192

def start_workers
  @worker_threads.clear # In case we're restarting the pipeline
  begin
    start_inputs
    @outputs.each {|o| o.register }
    @filters.each {|f| f.register }

    pipeline_workers = safe_pipeline_worker_count
    batch_size = @settings.get("pipeline.batch.size")
    batch_delay = @settings.get("pipeline.batch.delay")

    max_inflight = batch_size * pipeline_workers

    config_metric = metric.namespace([:stats, :pipelines, pipeline_id.to_s.to_sym, :config])
    config_metric.gauge(:workers, pipeline_workers)
    config_metric.gauge(:batch_size, batch_size)
    config_metric.gauge(:batch_delay, batch_delay)
    config_metric.gauge(:config_reload_automatic, @settings.get("config.reload.automatic"))
    config_metric.gauge(:config_reload_interval, @settings.get("config.reload.interval"))

    @logger.info("Starting pipeline",
                 "id" => self.pipeline_id,
                 "pipeline.workers" => pipeline_workers,
                 "pipeline.batch.size" => batch_size,
                 "pipeline.batch.delay" => batch_delay,
                 "pipeline.max_inflight" => max_inflight)
    if max_inflight > MAX_INFLIGHT_WARN_THRESHOLD
      @logger.warn "CAUTION: Recommended inflight events max exceeded! Logstash will run with up to #{max_inflight} events in memory in your current configuration. If your message sizes are large this may cause instability with the default heap size. Please consider setting a non-standard heap size, changing the batch size (currently #{batch_size}), or changing the number of pipeline workers (currently #{pipeline_workers})"
    end

    pipeline_workers.times do |t|
      @worker_threads << Thread.new do
        Util.set_thread_name("[#{pipeline_id}]>worker#{t}")
        worker_loop(batch_size, batch_delay)
      end
    end
  ensure
    # it is important to guarantee @ready to be true after the startup sequence has been completed
    # to potentially unblock the shutdown method which may be waiting on @ready to proceed
    @ready.make_true
  end
end

#stopped?Boolean

Returns:

  • (Boolean)


188
189
190
# File 'lib/logstash/pipeline.rb', line 188

def stopped?
  @running.false?
end

#transition_to_runningObject

def run



176
177
178
# File 'lib/logstash/pipeline.rb', line 176

def transition_to_running
  @running.make_true
end

#transition_to_stoppedObject



180
181
182
# File 'lib/logstash/pipeline.rb', line 180

def transition_to_stopped
  @running.make_false
end

#uptimeFixnum

Calculate the uptime in milliseconds

Returns:

  • (Fixnum)

    Uptime in milliseconds, 0 if the pipeline is not started



478
479
480
481
# File 'lib/logstash/pipeline.rb', line 478

def uptime
  return 0 if started_at.nil?
  ((Time.now.to_f - started_at.to_f) * 1000.0).to_i
end

#wait_inputsObject



303
304
305
# File 'lib/logstash/pipeline.rb', line 303

def wait_inputs
  @input_threads.each(&:join)
end

#worker_loop(batch_size, batch_delay) ⇒ Object

Main body of what a worker thread does Repeatedly takes batches off the queue, filters, then outputs them



237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
# File 'lib/logstash/pipeline.rb', line 237

def worker_loop(batch_size, batch_delay)
  running = true

  @filter_queue_client.set_batch_dimensions(batch_size, batch_delay)

  while running
    batch = @filter_queue_client.take_batch
    @events_consumed.increment(batch.size)
    running = false if batch.shutdown_signal_received?
    filter_batch(batch)

    if batch.shutdown_signal_received? || batch.flush_signal_received?
      flush_filters_to_batch(batch)
    end

    output_batch(batch)
    @filter_queue_client.close_batch(batch)
  end
end