Uploaded image for project: 'Ruby Driver'
  1. Ruby Driver
  2. RUBY-3044

Large bulk_write fails inside transactions

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Major - P3 Major - P3
    • 2.18.1, 2.17.3
    • Affects Version/s: 2.17.1, 2.18.0
    • Component/s: None
    • None

      When performing large bulk_writes, the write may internally be split into multiple smaller batches. This process increments the txn_num, which causes issues when an explicit transaction was used.

      Script to reproduce:

      require 'mongo'
      
      client = Mongo::Client.new('mongodb://127.0.0.1:27017/test')
      db = client.database
      collection = db['people']
      
      doc = {
        name: 'Steve',
        data: '.' * 20_000
      }
      op_count = 3_000
      doc_size = BSON::Document.new(doc).to_s.length
      total_size = doc_size * op_count
      puts "Size estimate: #{total_size}" # Should be > 48MB to trigger this issue
      
      client.start_session do |session|
        session.with_transaction do
          puts "In transaction: #{session.txn_num}"
          collection.bulk_write([{insert_one: doc}] * op_count, { session: session })
        rescue => e
          puts e.inspect
          puts e.backtrace
          raise e
        end
      end
      

      Output:

      Size estimate: 60087000
      In transaction: 1
      #<Mongo::Error::OperationFailure: [251:NoSuchTransaction]: Given transaction number 1 does not match any in-progress transactions. The active transaction number is -1 (on 127.0.0.1:27017, modern retry, attempt 1)>
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/operation/result.rb:364:in `raise_operation_failure'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/operation/result.rb:330:in `validate!'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write/result_combiner.rb:119:in `combine_write_errors!'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write/result_combiner.rb:109:in `combine_errors!'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write/result_combiner.rb:71:in `combine!'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:198:in `block (3 levels) in execute_operation'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/operation/shared/response_handling.rb:54:in `add_error_labels'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:197:in `block (2 levels) in execute_operation'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/operation/shared/response_handling.rb:108:in `add_server_diagnostics'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:196:in `block in execute_operation'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/operation/shared/response_handling.rb:94:in `unpin_maybe'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:190:in `execute_operation'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:222:in `split_execute'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:213:in `block in execute_operation'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/operation/shared/response_handling.rb:94:in `unpin_maybe'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:212:in `rescue in execute_operation'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:185:in `execute_operation'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:70:in `block (3 levels) in execute'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/retryable.rb:244:in `block in write_with_retry'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/server/connection_pool.rb:666:in `with_connection'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/server.rb:448:in `with_connection'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/retryable.rb:232:in `write_with_retry'
      ~/.rbenv/versions/2.7.6/lib/ruby/2.7.0/forwardable.rb:235:in `write_with_retry'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:69:in `block (2 levels) in execute'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:66:in `each'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:66:in `block in execute'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/client.rb:1120:in `with_session'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/bulk_write.rb:64:in `execute'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/collection.rb:718:in `bulk_write'
      test.rb:20:in `block (2 levels) in <main>'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/session.rb:436:in `block in with_transaction'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/session.rb:428:in `loop'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/session.rb:428:in `with_transaction'
      test.rb:18:in `block in <main>'
      ~/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/mongo-2.18.0.beta1/lib/mongo/client.rb:996:in `start_session'
      test.rb:17:in `<main>'
      W, [2022-07-07T11:49:53.326586 #730090]  WARN -- : MONGODB | Aborting transaction due to Mongo::Error::OperationFailure: [251:NoSuchTransaction]: Given transaction number 1 does not match any in-progress transactions. The active transaction number is -1 (on 127.0.0.1:27017, modern retry, attempt 1)
      

      The splitting of the batch is triggered by this:

      Message exceeds allowed max message size. The max is 48000000. (on 127.0.0.1:27017) (Mongo::Error::MaxMessageSize)
      

      Tested on:
      MongoDB 5.0.9, latest 6.0.0, latest unstable 6.1.0
      mongo-ruby-driver 2.17.1, 2.18.0-beta1
      Ruby 2.7.6
      Ubuntu 22.04

      A workaround is to split the batch into smaller batches on the app side.

            Assignee:
            dmitry.rybakov@mongodb.com Dmitry Rybakov
            Reporter:
            ralf@journeyapps.com Ralf Kistner
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: