Class: LogStash::Pipeline

Inherits:
BasePipeline show all
Defined in:
lib/logstash/pipeline.rb

Constant Summary collapse

MAX_INFLIGHT_WARN_THRESHOLD = 
10_000

Instance Attribute Summary collapse

Attributes inherited from BasePipeline

#config_hash, #config_str, #filters, #inputs, #outputs, #pipeline_id

Instance Method Summary collapse

Methods inherited from BasePipeline

#non_reloadable_plugins, #plugin, #reloadable?

Methods included from Util::Loggable

included, #logger, #slow_logger

Constructor Details

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

Returns a new instance of Pipeline.



132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
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
 
# File 'lib/logstash/pipeline.rb', line 132

def initialize(config_str, settings = SETTINGS, namespaced_metric = nil)
  # This needs to be configured before we call super which will evaluate the code to make
  # sure the metric instance is correctly send to the plugins to make the namespace scoping work
  @metric = if namespaced_metric
    settings.get("metric.collect") ? namespaced_metric : Instrument::NullMetric.new(namespaced_metric.collector)
  else
    Instrument::NullMetric.new
  end

  @settings = settings
  @reporter = PipelineReporter.new(@logger, self)
  @worker_threads = []

  super(config_str, settings)

  begin
    @queue = LogStash::QueueFactory.create(settings)
  rescue => e
    @logger.error("Logstash failed to create queue", "exception" => e.message, "backtrace" => e.backtrace)
    raise e
  end

  @input_queue_client = @queue.write_client
  @filter_queue_client = @queue.read_client
  @signal_queue = Queue.new
  # 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])
  )
  @drain_queue =  @settings.get_value("queue.drain")

  @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

#events_consumed ⇒ Object (readonly)

Returns the value of attribute events_consumed.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def events_consumed
  @events_consumed
end

#events_filtered ⇒ Object (readonly)

Returns the value of attribute events_filtered.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def events_filtered
  @events_filtered
end

#filter_queue_client ⇒ Object (readonly)

Returns the value of attribute filter_queue_client.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def filter_queue_client
  @filter_queue_client
end

#input_queue_client ⇒ Object (readonly)

Returns the value of attribute input_queue_client.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def input_queue_client
  @input_queue_client
end

#metric ⇒ Object (readonly)

Returns the value of attribute metric.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def metric
  @metric
end

#queue ⇒ Object (readonly)

Returns the value of attribute queue.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def queue
  @queue
end

#reporter ⇒ Object (readonly)

Returns the value of attribute reporter.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def reporter
  @reporter
end

#settings ⇒ Object (readonly)

Returns the value of attribute settings.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def settings
  @settings
end

#started_at ⇒ Object (readonly)

Returns the value of attribute started_at.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def started_at
  @started_at
end

#thread ⇒ Object (readonly)

Returns the value of attribute thread.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def thread
  @thread
end

#worker_threads ⇒ Object (readonly)

Returns the value of attribute worker_threads.



117
118
119
 
# File 'lib/logstash/pipeline.rb', line 117

def worker_threads
  @worker_threads
end

Instance Method Details

#close ⇒ Object

def run



239
240
241
242
 
# File 'lib/logstash/pipeline.rb', line 239

def close
  @filter_queue_client.close
  @queue.close
end

#collect_stats ⇒ Object 



589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
 
# File 'lib/logstash/pipeline.rb', line 589

def collect_stats
  pipeline_metric = @metric.namespace([:stats, :pipelines, pipeline_id.to_s.to_sym, :queue])
  pipeline_metric.gauge(:type, settings.get("queue.type"))

  if @queue.is_a?(LogStash::Util::WrappedAckedQueue) && @queue.queue.is_a?(LogStash::AckedQueue)
    queue = @queue.queue
    dir_path = queue.dir_path
    file_store = Files.get_file_store(Paths.get(dir_path))

    pipeline_metric.namespace([:capacity]).tap do |n|
      n.gauge(:page_capacity_in_bytes, queue.page_capacity)
      n.gauge(:max_queue_size_in_bytes, queue.max_size_in_bytes)
      n.gauge(:max_unread_events, queue.max_unread_events)
    end
    pipeline_metric.namespace([:data]).tap do |n|
      n.gauge(:free_space_in_bytes, file_store.get_unallocated_space)
      n.gauge(:storage_type, file_store.type)
      n.gauge(:path, dir_path)
    end

    pipeline_metric.gauge(:events, queue.unread_count)
  end
end

#filter(event, &block) ⇒ Object

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



511
512
513
514
 
# File 'lib/logstash/pipeline.rb', line 511

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 



368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
 
# File 'lib/logstash/pipeline.rb', line 368

def filter_batch(batch)
  batch.each do |event|
    filter_func(event).each do |e|
      #these are both original and generated events
      batch.merge(e) unless e.cancelled?
    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.message, "backtrace" => e.backtrace)

  raise e
end

#filters? ⇒ Boolean

Returns:

  • (Boolean) 


204
205
206
 
# File 'lib/logstash/pipeline.rb', line 204

def filters?
  return @filters.any?
end

#flush ⇒ Object 



544
545
546
547
548
549
 
# File 'lib/logstash/pipeline.rb', line 544

def flush
  if @flushing.compare_and_set(false, true)
    @logger.debug? && @logger.debug("Pushing flush onto pipeline")
    @signal_queue.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



520
521
522
523
524
525
526
 
# File 'lib/logstash/pipeline.rb', line 520

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: {}) 


564
565
566
567
568
569
570
571
572
573
 
# File 'lib/logstash/pipeline.rb', line 564

def flush_filters_to_batch(batch, options = {})
  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 



439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
 
# File 'lib/logstash/pipeline.rb', line 439

def inputworker(plugin)
  Util::set_thread_name("[#{pipeline_id}]<#{plugin.class.config_name}")
  begin
    input_queue_client = wrapped_write_client(plugin)
    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.message,
                    :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.message,
                           :exception => e.class,
                           :stacktrace => e.backtrace.join("\n")))
    else
      @logger.error(I18n.t("logstash.pipeline.worker-error",
                           :plugin => plugin.inspect, :error => e.message))
    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

#inspect ⇒ Object

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



616
617
618
619
620
621
622
623
624
 
# File 'lib/logstash/pipeline.rb', line 616

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

#output_batch(batch) ⇒ Object

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



391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
 
# File 'lib/logstash/pipeline.rb', line 391

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_threads_info ⇒ Object

flush_filters_to_batch



575
576
577
578
579
 
# File 'lib/logstash/pipeline.rb', line 575

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) 


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

def ready?
  @ready.value
end

#register_plugin(plugin) ⇒ Plugin

register_plugin simply calls the plugin #register method and catches & logs any error

Parameters:

  • plugin (Plugin) —

    the plugin to register

Returns:

  • (Plugin) —

    the registered plugin



267
268
269
270
271
272
273
 
# File 'lib/logstash/pipeline.rb', line 267

def register_plugin(plugin)
  plugin.register
  plugin
rescue => e
  @logger.error("Error registering plugin", :plugin => plugin.inspect, :error => e.message)
  raise e
end

#register_plugins(plugins) ⇒ Object

register_plugins calls #register_plugin on the plugins list and upon exception will call Plugin#do_close on all registered plugins

Parameters:

  • plugins (Array[Plugin]) —

    the list of plugins to register



277
278
279
280
281
282
283
 
# File 'lib/logstash/pipeline.rb', line 277

def register_plugins(plugins)
  registered = []
  plugins.each { |plugin| registered << register_plugin(plugin) }
rescue => e
  registered.each(&:do_close)
  raise e
end

#run ⇒ Object 



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
234
235
236
237
 
# File 'lib/logstash/pipeline.rb', line 208

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

  close

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

  # exit code
  return 0
end

#running? ⇒ Boolean

Returns:

  • (Boolean) 


252
253
254
 
# File 'lib/logstash/pipeline.rb', line 252

def running?
  @running.true?
end

#safe_pipeline_worker_count ⇒ Object 



179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
 
# File 'lib/logstash/pipeline.rb', line 179

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



475
476
477
478
479
480
481
482
483
484
485
486
487
488
 
# File 'lib/logstash/pipeline.rb', line 475

def shutdown(&before_stop)
  # shutdown can only start once the pipeline has completed its startup.
  # avoid potential race condition 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 concurrently?

  before_stop.call if block_given?

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

#shutdown_flusher ⇒ Object 



540
541
542
 
# File 'lib/logstash/pipeline.rb', line 540

def shutdown_flusher
  @flusher_thread.join
end

#shutdown_workers ⇒ Object

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



493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
 
# File 'lib/logstash/pipeline.rb', line 493

def shutdown_workers
  # Each worker thread will receive this exactly once!
  @worker_threads.each do |t|
    @logger.debug("Pushing shutdown", :thread => t.inspect)
    @signal_queue.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_info ⇒ Object 



581
582
583
584
585
586
587
 
# File 'lib/logstash/pipeline.rb', line 581

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_flusher ⇒ Object 



528
529
530
531
532
533
534
535
536
537
538
 
# File 'lib/logstash/pipeline.rb', line 528

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 



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

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

#start_inputs ⇒ Object 



417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
 
# File 'lib/logstash/pipeline.rb', line 417

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

  # first make sure we can register all input plugins
  register_plugins(@inputs)

  # then after all input plugins are successfully registered, start them
  @inputs.each { |input| start_input(input) }
end

#start_workers ⇒ Object 



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
330
331
332
333
334
335
 
# File 'lib/logstash/pipeline.rb', line 285

def start_workers
  @worker_threads.clear # In case we're restarting the pipeline
  begin
    register_plugins(@outputs)
    register_plugins(@filters)

    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

    # inputs should be started last, after all workers
    begin
      start_inputs
    rescue => e
      # if there is any exception in starting inputs, make sure we shutdown workers.
      # exception will already by logged in start_inputs
      shutdown_workers
      raise e
    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) 


256
257
258
 
# File 'lib/logstash/pipeline.rb', line 256

def stopped?
  @running.false?
end

#system? ⇒ Boolean

Returns:

  • (Boolean) 


260
261
262
 
# File 'lib/logstash/pipeline.rb', line 260

def system?
  settings.get_value("pipeline.system")
end

#transition_to_running ⇒ Object 



244
245
246
 
# File 'lib/logstash/pipeline.rb', line 244

def transition_to_running
  @running.make_true
end

#transition_to_stopped ⇒ Object 



248
249
250
 
# File 'lib/logstash/pipeline.rb', line 248

def transition_to_stopped
  @running.make_false
end

#uptime ⇒ Fixnum

Calculate the uptime in milliseconds

Returns:

  • (Fixnum) —

    Uptime in milliseconds, 0 if the pipeline is not started



555
556
557
558
 
# File 'lib/logstash/pipeline.rb', line 555

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

#wait_inputs ⇒ Object 



413
414
415
 
# File 'lib/logstash/pipeline.rb', line 413

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



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

def worker_loop(batch_size, batch_delay)
  shutdown_requested = false

  @filter_queue_client.set_batch_dimensions(batch_size, batch_delay)

  while true
    signal = @signal_queue.empty? ? NO_SIGNAL : @signal_queue.pop
    shutdown_requested |= signal.shutdown? # latch on shutdown signal

    batch = @filter_queue_client.read_batch # metrics are started in read_batch
    @events_consumed.increment(batch.size)
    filter_batch(batch)
    flush_filters_to_batch(batch, :final => false) if signal.flush?
    output_batch(batch)
    @filter_queue_client.close_batch(batch)

    # keep break at end of loop, after the read_batch operation, some pipeline specs rely on this "final read_batch" before shutdown.
    break if shutdown_requested && !draining_queue?
  end

  # we are shutting down, queue is drained if it was required, now  perform a final flush.
  # for this we need to create a new empty batch to contain the final flushed events
  batch = @filter_queue_client.new_batch
  @filter_queue_client.start_metrics(batch) # explicitly call start_metrics since we dont do a read_batch here
  flush_filters_to_batch(batch, :final => true)
  output_batch(batch)
  @filter_queue_client.close_batch(batch)
end