0.2.10

Fix toString method of LogStash::Timestamp

.gitignore

@@ -2,3 +2,4 @@
 Gemfile.lock
 Gemfile.bak
 .bundle
+.vagrant

.travis.yml

@@ -0,0 +1,8 @@
+language: ruby
+cache: bundler
+rvm:
+  - jruby
+before_script:
+  - wget http://search.maven.org/remotecontent?filepath=org/apache/derby/derby/10.12.1.1/derby-10.12.1.1.jar -O /tmp/derby.jar
+  - export JDBC_DERBY_JAR=/tmp/derby.jar
+script: bundle exec rspec

CHANGELOG.md

@@ -0,0 +1,36 @@
+# Change Log
+All notable changes to this project will be documented in this file, from 0.2.0.
+
+## [0.2.10] - 2016-07-07
+  - Support non-string entries in statement array
+  - Adds backtrace to exception logging
+
+## [0.2.9] - 2016-06-29
+  - Fix NameError exception. 
+  - Moved log_jdbc_exception calls
+
+## [0.2.7] - 2016-05-29
+  - Backport retry exception logic from v5 branch
+  - Backport improved timestamp compatibility from v5 branch
+
+## [0.2.6] - 2016-05-02
+  - Fix for exception infinite loop
+
+## [0.2.5] - 2016-04-11
+### Added
+  - Basic tests running against DerbyDB
+  - Fix for converting Logstash::Timestamp to iso8601 from @hordijk
+
+## [0.2.4] - 2016-04-07
+  - Documentation fixes from @hordijk
+
+## [0.2.3] - 2016-02-16
+  - Bug fixes
+
+## [0.2.2] - 2015-12-30
+  - Bug fixes
+
+## [0.2.1] -  2015-12-22
+  - Support for connection pooling support added through HikariCP
+  - Support for unsafe statement handling (allowing dynamic queries)
+  - Altered exception handling to now count sequential flushes with exceptions thrown

README.md

@@ -1,4 +1,7 @@
 # logstash-output-jdbc 
+
+[![Build Status](https://travis-ci.org/theangryangel/logstash-output-jdbc.svg?branch=master)](https://travis-ci.org/theangryangel/logstash-output-jdbc)
+
 This plugin is provided as an external plugin and is not part of the Logstash project.
 
 This plugin allows you to output to SQL databases, using JDBC adapters.
@@ -6,39 +9,41 @@ See below for tested adapters, and example configurations.
 
 This has not yet been extensively tested with all JDBC drivers and may not yet work for you.
 
-If you do find this works for a JDBC driver not listed, let me know and provide a small example configuration.
+If you do find this works for a JDBC driver without an example, let me know and provide a small example configuration if you can.
 
 This plugin does not bundle any JDBC jar files, and does expect them to be in a
 particular location. Please ensure you read the 4 installation lines below.
 
-## Headlines
+## ChangeLog
-  - Support for connection pooling added in 0.2.0
+See CHANGELOG.md
-  - Support for unsafe statement handling (allowing dynamic queries) in 0.2.0 
-  - Altered exception handling to now count sequential flushes with exceptions thrown in 0.2.0 
 
 ## Versions
-Released versions are are tagged as of v0.2.1, and available via rubygems.
+Released versions are available via rubygems, and typically tagged.
 
 For development:
-  - See master branch for logstash v2+
+  - See master branch for logstash v5
+  - See v2.x branch for logstash v2
   - See v1.5 branch for logstash v1.5 
   - See v1.4 branch for logstash 1.4
 
 ## Installation
   - Run `bin/plugin install logstash-output-jdbc` in your logstash installation directory
   - Now either:
-    - Use driver_path in your configuraton to specify a path to your jar file
+    - Use driver_jar_path in your configuraton to specify a path to your jar file
   - Or:
     - Create the directory vendor/jar/jdbc in your logstash installation (`mkdir -p vendor/jar/jdbc/`)
     - Add JDBC jar files to vendor/jar/jdbc in your logstash installation
   - And then configure (examples below)
 
 ## Running tests
-Assuming valid JDBC jar, and jruby is setup and installed, and you have issued `jruby -S bundle install` in the development directory
+At this time tests only run against Derby, in an in-memory database.
-  - `SQL_JAR=path/to/your.jar jruby -S bundle exec rspec`
+Acceptance tests for individual database engines will be added over time.
-If you need to provide username and password you may do this via the environment variables `SQL_USERNAME` and `SQL_PASSWORD`.
 
-Tests are not yet 100% complete.
+Assuming valid jruby is installed
+  - First time, issue `jruby -S bundle install` to install dependencies
+  - Next, download Derby jar from https://db.apache.org/derby/
+  - Run the tests `JDBC_DERBY_JAR=path/to/derby.jar jruby -S rspec`
+  - Optionally add the `JDBC_DEBUG=1` env variable to add logging to stdout
 
 ## Configuration options
 
@@ -46,7 +51,7 @@ Tests are not yet 100% complete.
 | ------ | ---- | ----------- | --------- | ------- |
 | driver_class | String | Specify a driver class if autoloading fails | No | |
 | driver_auto_commit | Boolean | If the driver does not support auto commit, you should set this to false | No | True |
-| driver_path | String | File path to jar file containing your JDBC driver. This is optional, and all JDBC jars may be placed in $LOGSTASH_HOME/vendor/jar/jdbc instead. | No | |
+| driver_jar_path | String | File path to jar file containing your JDBC driver. This is optional, and all JDBC jars may be placed in $LOGSTASH_HOME/vendor/jar/jdbc instead. | No | |
 | connection_string | String | JDBC connection URL | Yes | |
 | username | String | JDBC username - this is optional as it may be included in the connection string, for many drivers | No | |
 | password | String | JDBC password - this is optional as it may be included in the connection string, for many drivers | No | |

lib/logstash/outputs/jdbc.rb

@@ -6,10 +6,33 @@ require "java"
 require "logstash-output-jdbc_jars"
 require "logstash-output-jdbc_ring-buffer"
 
+# Write events to a SQL engine, using JDBC.
+#
+# It is upto the user of the plugin to correctly configure the plugin. This
+# includes correctly crafting the SQL statement, and matching the number of
+# parameters correctly.
 class LogStash::Outputs::Jdbc < LogStash::Outputs::Base
   # Adds buffer support
   include Stud::Buffer
 
+  STRFTIME_FMT = '%Y-%m-%d %T.%L'.freeze
+
+  RETRYABLE_SQLSTATE_CLASSES = [
+    # Classes of retryable SQLSTATE codes
+    # Not all in the class will be retryable. However, this is the best that 
+    # we've got right now.
+    # If a custom state code is required, set it in retry_sql_states.
+    '08', # Connection Exception
+    '24', # Invalid Cursor State (Maybe retry-able in some circumstances)
+    '25', # Invalid Transaction State 
+    '40', # Transaction Rollback 
+    '53', # Insufficient Resources
+    '54', # Program Limit Exceeded (MAYBE)
+    '55', # Object Not In Prerequisite State
+    '57', # Operator Intervention
+    '58', # System Error
+  ].freeze
+
   config_name "jdbc"
 
   # Driver class - Reintroduced for https://github.com/theangryangel/logstash-output-jdbc/issues/26
@@ -44,7 +67,7 @@ class LogStash::Outputs::Jdbc < LogStash::Outputs::Base
   config :max_pool_size, :validate => :number, :default => 5
 
   # Connection timeout
-  config :connection_timeout, :validate => :number, :default => 2800
+  config :connection_timeout, :validate => :number, :default => 10000
 
   # We buffer a certain number of events before flushing that out to SQL.
   # This setting controls how many events will be buffered before sending a
@@ -128,7 +151,6 @@ class LogStash::Outputs::Jdbc < LogStash::Outputs::Base
 
     if @exceptions_tracker.reject { |i| i.nil? }.count >= @max_flush_exceptions
       @logger.error("JDBC - max_flush_exceptions has been reached")
-      log_jdbc_exception(e)
       raise LogStash::ShutdownSignal.new
     end
   end
@@ -156,9 +178,11 @@ class LogStash::Outputs::Jdbc < LogStash::Outputs::Base
     @pool.setMaximumPoolSize(@max_pool_size)
     @pool.setConnectionTimeout(@connection_timeout)
 
+    validate_connection_timeout = (@connection_timeout / 1000) / 2
+
     # Test connection
     test_connection = @pool.getConnection()
-    unless test_connection.isValid(10)
+    unless test_connection.isValid(validate_connection_timeout)
       @logger.error("JDBC - Connection is not valid. Please check connection string or that your JDBC endpoint is available.")
     end
     test_connection.close()
@@ -192,7 +216,17 @@ class LogStash::Outputs::Jdbc < LogStash::Outputs::Base
   end
 
   def safe_flush(events, teardown=false)
+    connection = nil
+    statement = nil
+    
+    begin
       connection = @pool.getConnection()
+    rescue => e
+      log_jdbc_exception(e, true)
+      raise
+    end
+
+    begin
       statement = connection.prepareStatement(@statement[0])
 
       events.each do |event|
@@ -203,82 +237,116 @@ class LogStash::Outputs::Jdbc < LogStash::Outputs::Base
         statement.addBatch()
       end
 
-    begin
       statement.executeBatch()
       statement.close()
       @exceptions_tracker << nil
-      
     rescue => e
-      # Raising an exception will incur a retry from Stud::Buffer.
+      if retry_exception?(e)
-      # Since the exceutebatch failed this should mean any events failed to be
+        raise
-      # inserted will be re-run. We're going to log it for the lols anyway.
+      end
-      log_jdbc_exception(e)
     ensure
-      connection.close();
+      statement.close() unless statement.nil?
+      connection.close() unless connection.nil?
     end
   end
 
   def unsafe_flush(events, teardown=false)
+    connection = nil
+    statement = nil
+    begin
       connection = @pool.getConnection()
+    rescue => e
+      log_jdbc_exception(e, true)
+      raise
+    end
 
+    begin
       events.each do |event|
         next if event.cancelled?
 
         statement = connection.prepareStatement(event.sprintf(@statement[0]))
         statement = add_statement_event_params(statement, event) if @statement.length > 1
 
-      begin
         statement.execute()
 
         # cancel the event, since we may end up outputting the same event multiple times
         # if an exception happens later down the line
         event.cancel
         @exceptions_tracker << nil
-      rescue => e
-        # Raising an exception will incur a retry from Stud::Buffer.
-        # We log for the lols.
-        log_jdbc_exception(e)
-      ensure
-        statement.close()
-        connection.close()
       end
+    rescue => e
+      if retry_exception?(e)
+        raise
+      end
+    ensure
+      statement.close() unless statement.nil?
+      connection.close() unless connection.nil?
     end
   end
 
   def add_statement_event_params(statement, event)
     @statement[1..-1].each_with_index do |i, idx|
-      case event[i]
+      if i.is_a? String 
-      when Time, LogStash::Timestamp
+        value = event[i]
-        # Most reliable solution, cross JDBC driver
+        if value.nil? and i =~ /%\{/
-        statement.setString(idx + 1, event[i].iso8601())
+          value = event.sprintf(i)
-      when Fixnum, Integer
+        end
-        statement.setInt(idx + 1, event[i])
-      when Float
-        statement.setFloat(idx + 1, event[i])
-      when String
-        statement.setString(idx + 1, event[i])
-      when true
-        statement.setBoolean(idx + 1, true)
-      when false
-        statement.setBoolean(idx + 1, false)
       else
-        if event[i].nil? and i =~ /%\{/
+        value = i
-          statement.setString(idx + 1, event.sprintf(i))
+      end
+      
+      case value
+      when Time
+        # See LogStash::Timestamp, below, for the why behind strftime.
+        statement.setString(idx + 1, value.strftime(STRFTIME_FMT))
+      when LogStash::Timestamp
+        # XXX: Using setString as opposed to setTimestamp, because setTimestamp
+        # doesn't behave correctly in some drivers (Known: sqlite)
+        #
+        # Additionally this does not use `to_iso8601`, since some SQL databases
+        # choke on the 'T' in the string (Known: Derby).
+        #
+        # strftime appears to be the most reliable across drivers.
+        statement.setString(idx + 1, value.time.strftime(STRFTIME_FMT))
+      when Fixnum, Integer
+        statement.setInt(idx + 1, value)
+      when Float
+        statement.setFloat(idx + 1, value)
+      when String
+        statement.setString(idx + 1, value)
+      when true, false
+        statement.setBoolean(idx + 1, value)
       else
         statement.setString(idx + 1, nil)
       end
     end
-    end
 
     statement
   end
 
-  def log_jdbc_exception(e)
+
-    ce = e
+  def log_jdbc_exception(exception, retrying)
+    current_exception = exception
+    log_text = 'JDBC - Exception. ' + (retrying ? 'Retrying' : 'Not retrying') + '.'
+    log_method = (retrying ? 'warn' : 'error')
+
     loop do
-      @logger.error("JDBC Exception encountered: Will automatically retry.", :exception => ce)
+      @logger.send(log_method, log_text, :exception => current_exception, :backtrace => current_exception.backtrace)
-      ce = e.getNextException()
+
-      break if ce == nil
+      if current_exception.respond_to? 'getNextException'
+        current_exception = current_exception.getNextException()
+      else
+        current_exception = nil
       end
+
+      break if current_exception == nil
+    end
+  end
+
+  def retry_exception?(exception)
+    retrying = (exception.respond_to? 'getSQLState' and RETRYABLE_SQLSTATE_CLASSES.include?(exception.getSQLState.to_s[0,2]))
+    log_jdbc_exception(exception, retrying)
+
+    retrying
   end
 end # class LogStash::Outputs::jdbc

logstash-output-jdbc.gemspec

@@ -1,6 +1,6 @@
 Gem::Specification.new do |s|
   s.name = 'logstash-output-jdbc'
-  s.version = "0.2.2"
+  s.version = "0.2.10"
   s.licenses = [ "Apache License (2.0)" ]
   s.summary = "This plugin allows you to output to SQL, via JDBC"
   s.description = "This gem is a logstash plugin required to be installed on top of the Logstash core pipeline using $LS_HOME/bin/plugin install gemname. This gem is not a stand-alone program"
@@ -19,11 +19,11 @@ Gem::Specification.new do |s|
   s.metadata = { "logstash_plugin" => "true", "logstash_group" => "output" }
 
   # Gem dependencies
-  s.add_runtime_dependency "logstash-core", ">= 2.0.0.beta2", "< 3.0.0"
   s.add_runtime_dependency 'stud'
+
+  s.add_runtime_dependency "logstash-core", ">= 2.0.0", "< 3.0.0"
   s.add_runtime_dependency "logstash-codec-plain"
 
-  s.add_development_dependency "logstash-devutils"
+  # https://github.com/elastic/logstash-devutils/issues/48
-
+  s.add_development_dependency "logstash-devutils", '0.0.18'
-  s.post_install_message = "logstash-output-jdbc 0.2.0 introduces several new features - please ensure you check the documentation in the README file"
 end

spec/outputs/jdbc_spec.rb

@@ -4,92 +4,91 @@ require "stud/temporary"
 require "java"
 
 describe LogStash::Outputs::Jdbc do
-  def fetch_log_table_rowcount
+
-    # sleep for a second to let the flush happen
+  let(:derby_settings) do
+    { 
+      "driver_class" => "org.apache.derby.jdbc.EmbeddedDriver",
+      "connection_string" => "jdbc:derby:memory:testdb;create=true",
+      "driver_jar_path" => ENV['JDBC_DERBY_JAR'],
+      "statement" => [ "insert into log (created_at, message) values(?, ?)", "@timestamp" "message" ]
+    }
+  end
+
+  context 'rspec setup' do
+
+    it 'ensure derby is available' do
+      j = ENV['JDBC_DERBY_JAR']
+      expect(j).not_to be_nil, "JDBC_DERBY_JAR not defined, required to run tests"
+      expect(File.exists?(j)).to eq(true), "JDBC_DERBY_JAR defined, but not valid"
+    end
+    
+  end
+
+  context 'when initializing' do
+
+    it 'shouldn\'t register without a config' do
+      expect { 
+        LogStash::Plugin.lookup("output", "jdbc").new()
+      }.to raise_error(LogStash::ConfigurationError)
+    end
+
+    it 'shouldn\'t register with a missing jar file' do
+      derby_settings['driver_jar_path'] = nil
+      plugin = LogStash::Plugin.lookup("output", "jdbc").new(derby_settings)
+      expect { plugin.register }.to raise_error
+    end
+
+    it 'shouldn\'t register with a missing jar file' do
+      derby_settings['connection_string'] = nil
+      plugin = LogStash::Plugin.lookup("output", "jdbc").new(derby_settings)
+      expect { plugin.register }.to raise_error
+    end
+
+  end
+
+  context 'when outputting messages' do
+
+    let(:event_fields) do
+      { message: 'test-message' }
+    end
+    let(:event) { LogStash::Event.new(event_fields) }
+    let(:plugin) {
+      # Setup plugin
+      output = LogStash::Plugin.lookup("output", "jdbc").new(derby_settings)
+      output.register
+      if ENV['JDBC_DEBUG'] == '1'
+        output.logger.subscribe(STDOUT)
+      end
+
+      # Setup table
+      c = output.instance_variable_get(:@pool).getConnection()
+      stmt = c.createStatement()
+      stmt.executeUpdate("CREATE table log (created_at timestamp, message varchar(512))")
+      stmt.close()
+      c.close()
+
+      output
+    }
+
+    it 'should save a event' do
+      expect { plugin.receive(event) }.to_not raise_error
+      
+      # Wait for 1 second, for the buffer to flush
       sleep 1
 
-    stmt = @sql.createStatement()
+      c = plugin.instance_variable_get(:@pool).getConnection()
+      stmt = c.createStatement()
       rs = stmt.executeQuery("select count(*) as total from log")
       count = 0
       while rs.next()
         count = rs.getInt("total")
       end
       stmt.close()
+      c.close()
 
-    return count
+      expect(count).to be > 0
-  end
-
-  let(:base_settings) { { 
-    "driver_jar_path" => @driver_jar_path,
-    "connection_string" => @test_connection_string, 
-    "username" => ENV['SQL_USERNAME'],
-    "password" => ENV['SQL_PASSWORD'],
-    "statement" => [ "insert into log (message) values(?)", "message" ],
-    "max_pool_size" => 1,
-    "flush_size" => 1,
-    "max_flush_exceptions" => 1
-  } }
-  let(:test_settings) { {} }
-  let(:plugin) { LogStash::Outputs::Jdbc.new(base_settings.merge(test_settings)) }
-  let(:event_fields) { { "message" => "This is a message!" } }
-  let(:event) { LogStash::Event.new(event_fields) }
-
-  before(:all) do
-    @driver_jar_path = File.absolute_path(ENV['SQL_JAR'])
-    @test_db_path = File.join(Stud::Temporary.directory, "test.db")
-    @test_connection_string = "jdbc:sqlite:#{@test_db_path}"
-
-    require @driver_jar_path
-
-    @sql = java.sql.DriverManager.get_connection(@test_connection_string, ENV['SQL_USERNAME'].to_s, ENV['SQL_PASSWORD'].to_s)
-    stmt = @sql.createStatement()
-    stmt.executeUpdate("CREATE table log (host text, timestamp datetime, message text);")
-    stmt.close()
-  end
-
-  before(:each) do
-    stmt = @sql.createStatement()
-    stmt.executeUpdate("delete from log")
-    stmt.close()
-  end
-
-  after(:all) do
-   File.unlink(@test_db_path) 
-   Dir.rmdir(File.dirname(@test_db_path))
-  end
-
-  describe "safe statement" do
-    it "should register without errors" do
-      expect { plugin.register }.to_not raise_error
-    end
-
-    it "receive event, without error" do
-      plugin.register
-      expect { plugin.receive(event) }.to_not raise_error
-
-      expect(fetch_log_table_rowcount).to eq(1)
     end
 
   end
 
-  describe "unsafe statement" do
-    let(:event_fields) {
-      { "message" => "This is a message!", "table" => "log" }
-    }
-    let(:test_settings) { {
-      "statement" => [ "insert into %{table} (message) values(?)", "message" ],
-      "unsafe_statement" => true
-    } }
-    
-    it "should register without errors" do
-      expect { plugin.register }.to_not raise_error
-    end
-
-    it "receive event, without error" do
-      plugin.register
-      plugin.receive(event)
-      expect(fetch_log_table_rowcount).to eq(1)
-    end
-    
-  end
 end