Class: LogStash::JavaPipeline

Inherits:
JavaBasePipeline show all
Defined in:
lib/logstash/java_pipeline.rb

Constant Summary collapse

MAX_INFLIGHT_WARN_THRESHOLD =
10_000

Instance Attribute Summary collapse

Attributes inherited from JavaBasePipeline

#config_hash, #config_str, #ephemeral_id, #execution_context, #filters, #inputs, #lir, #outputs, #pipeline_config, #pipeline_id

Instance Method Summary collapse

Methods inherited from JavaBasePipeline

#buildCodec, #buildFilter, #buildInput, #buildOutput, #close_dlq_writer, #configured_as_reloadable?, #dlq_writer, #non_reloadable_plugins, #plugin, #reloadable?, #reloadable_plugins?

Methods included from Util::Loggable

included, #logger, #slow_logger

Constructor Details

#initialize(pipeline_config, namespaced_metric = nil, agent = nil) ⇒ JavaPipeline

Returns a new instance of JavaPipeline.



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
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
# File 'lib/logstash/java_pipeline.rb', line 146

def initialize(pipeline_config, namespaced_metric = nil, agent = nil)
  @settings = pipeline_config.settings
  # 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

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

  super

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

  @input_queue_client = @queue.write_client
  @filter_queue_client = @queue.read_client
  @signal_queue = java.util.concurrent.LinkedBlockingQueue.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)
  @outputs_registered = Concurrent::AtomicBoolean.new(false)
  @finished_execution = Concurrent::AtomicBoolean.new(false)
end

Instance Attribute Details

#events_consumedObject (readonly)

Returns the value of attribute events_consumed.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def events_consumed
  @events_consumed
end

#events_filteredObject (readonly)

Returns the value of attribute events_filtered.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def events_filtered
  @events_filtered
end

#filter_queue_clientObject (readonly)

Returns the value of attribute filter_queue_client.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def filter_queue_client
  @filter_queue_client
end

#input_queue_clientObject (readonly)

Returns the value of attribute input_queue_client.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def input_queue_client
  @input_queue_client
end

#metricObject (readonly)

Returns the value of attribute metric.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def metric
  @metric
end

#queueObject (readonly)

Returns the value of attribute queue.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def queue
  @queue
end

#reporterObject (readonly)

Returns the value of attribute reporter.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def reporter
  @reporter
end

#settingsObject (readonly)

Returns the value of attribute settings.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def settings
  @settings
end

#started_atObject (readonly)

Returns the value of attribute started_at.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def started_at
  @started_at
end

#threadObject (readonly)

Returns the value of attribute thread.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def thread
  @thread
end

#worker_threadsObject (readonly)

Returns the value of attribute worker_threads.



131
132
133
# File 'lib/logstash/java_pipeline.rb', line 131

def worker_threads
  @worker_threads
end

Instance Method Details

#clear_pipeline_metricsObject



622
623
624
625
626
627
628
629
630
631
632
633
634
# File 'lib/logstash/java_pipeline.rb', line 622

def clear_pipeline_metrics
  # TODO(ph): I think the metric should also proxy that call correctly to the collector
  # this will simplify everything since the null metric would simply just do a noop
  collector = @metric.collector

  unless collector.nil?
    # selectively reset metrics we don't wish to keep after reloading
    # these include metrics about the plugins and number of processed events
    # we want to keep other metrics like reload counts and error messages
    collector.clear("stats/pipelines/#{pipeline_id}/plugins")
    collector.clear("stats/pipelines/#{pipeline_id}/events")
  end
end

#closeObject

def run



303
304
305
306
307
# File 'lib/logstash/java_pipeline.rb', line 303

def close
  @filter_queue_client.close
  @queue.close
  close_dlq_writer
end

#collect_dlq_statsObject



591
592
593
594
595
596
# File 'lib/logstash/java_pipeline.rb', line 591

def collect_dlq_stats
  if dlq_enabled?
    dlq_metric = @metric.namespace([:stats, :pipelines, pipeline_id.to_s.to_sym, :dlq])
    dlq_metric.gauge(:queue_size_in_bytes, @dlq_writer.get_current_queue_size)
  end
end

#collect_statsObject



598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
# File 'lib/logstash/java_pipeline.rb', line 598

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)
      n.gauge(:queue_size_in_bytes, queue.persisted_size_in_bytes)
    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

#dlq_enabled?Boolean

Returns:

  • (Boolean)


400
401
402
# File 'lib/logstash/java_pipeline.rb', line 400

def dlq_enabled?
  @settings.get("dead_letter_queue.enable")
end

#filter(event, &block) ⇒ Object

for backward compatibility in devutils for the rspec helpers, this method is not used anymore and just here to not break TestPipeline that inherits this class.



538
539
# File 'lib/logstash/java_pipeline.rb', line 538

def filter(event, &block)
end

#filters?Boolean

Returns:

  • (Boolean)


221
222
223
# File 'lib/logstash/java_pipeline.rb', line 221

def filters?
  @filters.any?
end

#flushObject



562
563
564
565
566
567
# File 'lib/logstash/java_pipeline.rb', line 562

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

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

for backward compatibility in devutils for the rspec helpers, this method is not used anymore and just here to not break TestPipeline that inherits this class.



543
544
# File 'lib/logstash/java_pipeline.rb', line 543

def flush_filters(options = {}, &block)
end

#inputworker(plugin) ⇒ Object



454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
# File 'lib/logstash/java_pipeline.rb', line 454

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.",
                    default_logging_keys(:plugin => plugin.class.config_name, :exception => e.message, :backtrace => e.backtrace))
      return
    end

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

    # 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



639
640
641
642
643
644
645
646
647
# File 'lib/logstash/java_pipeline.rb', line 639

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

#plugin_threads_infoObject



577
578
579
580
581
# File 'lib/logstash/java_pipeline.rb', line 577

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)


193
194
195
# File 'lib/logstash/java_pipeline.rb', line 193

def ready?
  @ready.value
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



331
332
333
334
335
336
337
338
339
340
# File 'lib/logstash/java_pipeline.rb', line 331

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

#runObject



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

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

  start_workers

  @logger.info("Pipeline started", "pipeline.id" => @pipeline_id)

  # 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.", default_logging_keys)

  shutdown_flusher
  shutdown_workers

  close

  @logger.debug("Pipeline has been shutdown", default_logging_keys)

  # exit code
  return 0
end

#running?Boolean

Returns:

  • (Boolean)


317
318
319
# File 'lib/logstash/java_pipeline.rb', line 317

def running?
  @running.true?
end

#safe_pipeline_worker_countObject



197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
# File 'lib/logstash/java_pipeline.rb', line 197

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", default_logging_keys(: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",
                   default_logging_keys(: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



486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
# File 'lib/logstash/java_pipeline.rb', line 486

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?

  stop_inputs

  # We make this call blocking, so we know for sure when the method return the shtudown is
  # stopped
  wait_for_workers
  clear_pipeline_metrics
  @logger.info("Pipeline terminated", "pipeline.id" => @pipeline_id)
end

#shutdown_flusherObject



558
559
560
# File 'lib/logstash/java_pipeline.rb', line 558

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



520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
# File 'lib/logstash/java_pipeline.rb', line 520

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

  @worker_threads.each do |t|
    @logger.debug("Shutdown waiting for worker thread" , default_logging_keys(:thread => t.inspect))
    t.join
  end

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

#stalling_threads_infoObject



583
584
585
586
587
588
589
# File 'lib/logstash/java_pipeline.rb', line 583

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

#startObject



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

def start
  # Since we start lets assume that the metric namespace is cleared
  # this is useful in the context of pipeline reloading
  collect_stats
  collect_dlq_stats

  @logger.debug("Starting pipeline", default_logging_keys)

  @finished_execution.make_false

  @thread = Thread.new do
    begin
      LogStash::Util.set_thread_name("pipeline.#{pipeline_id}")
      run
      @finished_execution.make_true
    rescue => e
      close
      logger.error("Pipeline aborted due to error", default_logging_keys(:exception => e, :backtrace => e.backtrace))
    end
  end

  status = wait_until_started

  if status
    logger.debug("Pipeline started successfully", default_logging_keys(:pipeline_id => pipeline_id))
  end

  status
end

#start_flusherObject



546
547
548
549
550
551
552
553
554
555
556
# File 'lib/logstash/java_pipeline.rb', line 546

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



450
451
452
# File 'lib/logstash/java_pipeline.rb', line 450

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

#start_inputsObject



432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
# File 'lib/logstash/java_pipeline.rb', line 432

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_workersObject



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

def start_workers
  @worker_threads.clear # In case we're restarting the pipeline
  @outputs_registered.make_false
  begin
    maybe_setup_out_plugins

    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"))
    config_metric.gauge(:dead_letter_queue_enabled, dlq_enabled?)
    config_metric.gauge(:dead_letter_queue_path, @dlq_writer.get_path.to_absolute_path.to_s) if dlq_enabled?


    @logger.info("Starting pipeline", default_logging_keys(
      "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})", default_logging_keys)
    end

    @filter_queue_client.set_batch_dimensions(batch_size, batch_delay)

    pipeline_workers.times do |t|
      batched_execution = @lir_execution.buildExecution
      thread = Thread.new(self, batched_execution) do |_pipeline, _batched_execution|
        _pipeline.worker_loop(_batched_execution)
      end
      thread.name="[#{pipeline_id}]>worker#{t}"
      @worker_threads << thread
    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

#stop_inputsObject



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

def stop_inputs
  @logger.debug("Closing inputs", default_logging_keys)
  @inputs.each(&:do_stop)
  @logger.debug("Closed inputs", default_logging_keys)
end

#stopped?Boolean

Returns:

  • (Boolean)


321
322
323
# File 'lib/logstash/java_pipeline.rb', line 321

def stopped?
  @running.false?
end

#system?Boolean

Returns:

  • (Boolean)


325
326
327
# File 'lib/logstash/java_pipeline.rb', line 325

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

#transition_to_runningObject



309
310
311
# File 'lib/logstash/java_pipeline.rb', line 309

def transition_to_running
  @running.make_true
end

#transition_to_stoppedObject



313
314
315
# File 'lib/logstash/java_pipeline.rb', line 313

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



572
573
574
575
# File 'lib/logstash/java_pipeline.rb', line 572

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

#wait_for_workersObject

def shutdown



505
506
507
508
509
# File 'lib/logstash/java_pipeline.rb', line 505

def wait_for_workers
  @logger.debug("Closing inputs", default_logging_keys)
  @worker_threads.map(&:join)
  @logger.debug("Worker closed", default_logging_keys)
end

#wait_inputsObject



428
429
430
# File 'lib/logstash/java_pipeline.rb', line 428

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

#wait_until_startedObject



255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
# File 'lib/logstash/java_pipeline.rb', line 255

def wait_until_started
  while true do
    # This should be changed with an appropriate FSM
    # It's an edge case, if we have a pipeline with
    # a generator { count => 1 } its possible that `Thread#alive?` doesn't return true
    # because the execution of the thread was successful and complete
    if @finished_execution.true?
      return true
    elsif thread.nil? || !thread.alive?
      return false
    elsif running?
      return true
    else
      sleep 0.01
    end
  end
end

#worker_loop(batched_execution) ⇒ Object

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



406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
# File 'lib/logstash/java_pipeline.rb', line 406

def worker_loop(batched_execution)
  shutdown_requested = false
  while true
    signal = @signal_queue.poll || NO_SIGNAL
    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)
    execute_batch(batched_execution, batch, signal.flush?)
    @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
  batched_execution.compute(batch.to_a, true, true)
  @filter_queue_client.close_batch(batch)
end