Thread safe on checking transaction_finished?

[treviateo]

Hi,

Just wondering whether the following method in Sequel::Database class (transactions.rb):

def transaction_finished?(conn)
  if supports_savepoints?
    stack = _trans(conn)[:savepoints]
    stack.pop
    stack.empty?
  else
    true
  end
end

is protected against multiple threads ?

The '_trans(conn)' is protected against multiple threads as 'Sequel.synchronize{@Transactions[conn]}', but once the threads have gained access to the current transactions of the connection, is it possible that 2 threads could possibly access the [:savepoints] at the same time and the transaction_finished? method could return as not finished and Sequel.synchronize{@transactions.delete(conn)} won't be executed (and there will be undefined method [] for nil class error on the following line:
if opts[:savepoint] != false && (stack = _trans(conn)[:savepoints]) && stack.last[:auto_savepoint] line 221 transactions.rb) ?

Thank you.

[jeremyevans]

This is thread safe. conn can only be checked out to a single thread at the same time. So only the hash access needs a mutex check, not subsequent actions on the hash values.

[treviateo]

Hi Jeremy,

When you mentioned that only 'the hash access needs a mutex check', did you mean '_trans(conn) which is Sequel.synchronize{@Transactions[conn]}' or '_trans(conn)[:savepoints]' ?

Just want to run through you the following scenarios with the current [:savepoints] contains 2 elements:

Just try to dig deeper about the possibility here, because we experienced an error 'undefined method [] for nil class' (from the line: if opts[:savepoint] != false && (stack = _trans(conn)[:savepoints]) && stack.last[:auto_savepoint] - line 221 transactions.rb)) while running many concurrent processing that has many DB.transaction boundary, and cannot recover from the error unless re-initialize the DB connection.

Thank you for your help.

[jeremyevans]

@transactions is a Database instance variable accessed by multiple threads, that needs a mutex check (and has one). The value returned is a hash, but no other threads should be accessing that hash at the same time, because each conn can only be checked out to a single thread at a time.

The connection pool handles checkouts of conn, so one possible cause is if there was a bug in the connection pool, but you would probably have much larger issues (unrelated to transactions) if that were the case.

Another possible cause is something is reaching into either the Database internals or connection pool internals instead of using the public APIs.

Another possible cause is that you are using fibers to do Database work without using Sequel's fiber_concurrency extension.

Another possible cause is that separate conn objects compare equal. I'm not sure if any driver implements equality comparison for connection objects, but if it did, you could try this patch:

diff --git a/lib/sequel/database/misc.rb b/lib/sequel/database/misc.rb
index 3ebae3d3b..f77e051e2 100644
--- a/lib/sequel/database/misc.rb
+++ b/lib/sequel/database/misc.rb
@@ -149,6 +149,7 @@ module Sequel
       @schemas = {}
       @prepared_statements = {}
       @transactions = {}
+      @transactions.compare_by_identity
       @symbol_literal_cache = {}

       @timezone = nil

From reviewing the code, another possible cause is if there was an interrupt or some other exception inside remove_transaction. However, unless you were swallowing such an exception, you should have evidence of that.

If you have a self contained reproducible example, I would definitely like to test it.

[treviateo]

Hi Jeremy,

Thank you for your response and advice, really appreciate it.

Unfortunately, we do not have a self contained example that can keep reproducing the issue. The error occurred twice (first time on 19 Jan and second time on 17 Feb) on an environment that runs many concurrent processes running 24/7 and access the same database. The first time the error is 'cannot set :retry_on options if you are already inside a transaction' and the second time is 'undefined method `[]' for nil:NilClass' (both from within def transaction method within transactions.rb). Once the app encountered this error, the same error will keep occurring (cannot recover from it) unless the app server is restarted (which reinitialize a new db connection / db object).

Just wondering, for line 227 in transactions.rb: _'if opts[:savepoint] != false && (stack = trans(conn)[:savepoints]) && stack.last[:auto_savepoint]', may we have a nil safe check on the 'stack' and raise a Sequel::Error (similar to the error raised for 'cannot set :retry_on options if you are already inside a transaction') to help use catching the error ?

Thank you.

[jeremyevans]

For cannot set :retry_on options if you are already inside a transaction, that should only occur if you are passing :retry_on option when already inside a transaction, which you should not be doing. It still shouldn't cause the second issue, but it seems like a workaround until the problem is determined would be to avoid that issue. If you have a backtrace from that error, it should be easy to see what code is setting the :retry_on option, and fix it to not set it.

Here's a diff for the change you are asking for:

diff --git a/lib/sequel/database/transactions.rb b/lib/sequel/database/transactions.rb
index d53002ff9..c73d8085d 100644
--- a/lib/sequel/database/transactions.rb
+++ b/lib/sequel/database/transactions.rb
@@ -224,8 +224,14 @@ module Sequel
               end
             end

-            if opts[:savepoint] != false && (stack = _trans(conn)[:savepoints]) && stack.last[:auto_savepoint]
-              opts[:savepoint] = true
+            if opts[:savepoint] != false && (stack = _trans(conn)[:savepoints])
+              if last_frame = stack.last
+                if last_frame[:auto_savepoint]
+                  opts[:savepoint] = true
+                end
+              else
+                raise Sequel::Error, "empty transaction savepoint stack"
+              end
             end

             unless opts[:savepoint]

That diff should at least be able to tell you if the NilClass#[] issue is in (stack = _trans(conn)[:savepoints] or in stack.last[:auto_savepoint]

If you want to try to reproduce this outside of the application, a program with multiple threads each with a loop that opens a transaction, opens a savepoint, and improperly uses the :retry_on option inside the transaction would probably be the best way.

[jeremyevans]

Here's a test program I came up with (run with ruby bin/sequel mock://postgres filename):

4.times.map do |i|
  Thread.new do
    i = i.to_s
    n = 0
    serrors = 0
    terrors = 0
    loop do
      n += 1
      print i if n % 1000 == 0
      DB.transaction do
        DB.transaction(savepoint: true) do
          DB.transaction(retry_on: RuntimeError) do
          end
        rescue Sequel::Error
          serrors += 1
          print 'S' if serrors % 1000 == 0
        end
        DB.transaction(retry_on: RuntimeError) do
        end
      rescue Sequel::Error
        terrors += 1
        print 'T' if terrors % 1000 == 0
        DB.transaction(savepoint: true) do
        end
      end
    end
  end
end.map(&:join)

It doesn't fail in my Windows or OpenBSD environment, either on CRuby or JRuby. It should fail with the NoMethodError you experienced if there is actually a race condition. So my guess is there is something else going on.

[treviateo]

Hi Jeremy, thank you, really appreciate your help and advice.

At the moment, we try to use the skip_transaction option at places that we thought they should not require to execute within a transaction to reduce the chance to encounter the error.

You are probably right that there is something else going on. We are on JRuby 9.4.2.0 and looking at the following section (def _transaction in transactions.rb):

Just wondering is there any chance that somehow the 'ensure remove_transaction(conn, committed)' is not executed (because that section has a couple of nested begin rescue blocks) due to the JRuby interpreter behavior ?

Thank you.

[jeremyevans]

You could try updating to JRuby 9.4.6.0 (released a couple days ago), and see if that helps. I'm not aware of any JRuby bugs that would cause the issues you are having, but I only use JRuby for testing and do not follow JRuby development closely.