Skip to content

Instantly share code, notes, and snippets.

@jpr5
Created February 9, 2011 05:59
Show Gist options
  • Star 1 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save jpr5/817987 to your computer and use it in GitHub Desktop.
Save jpr5/817987 to your computer and use it in GitHub Desktop.
bad bug in DM/DO nested transactions (FIXED in 03ae081f28a6143478e2174ccf3bd233e82cb91b)
#!/usr/bin/ruby
[
'addressable.git', 'extlib.git',
'do.git/data_objects', 'do.git/do_mysql',
'dm-core.git', 'dm-migrations.git', 'dm-transactions.git', 'dm-do-adapter.git', 'dm-mysql-adapter-1.0.0',
].each do |path|
$:.unshift "common/gems/#{path}/lib"
end
require 'data_objects'
require 'dm-core'
require 'dm-migrations'
require 'dm-transactions'
class Foo
include ::DataMapper::Resource
property :id, Serial
end
class Bar
include ::DataMapper::Resource
property :id, Serial
property :dongs, String
property :balls, String
end
::DataMapper.setup(:default, 'mysql://127.0.0.1/test')
::DataMapper.auto_migrate!
def log(msg)
warn "[#{Thread.current.object_id}] #{msg}"
end
log "starting"
mutex = Mutex.new
cv = ConditionVariable.new
Thread.new do
Thread.abort_on_exception = true
while true
log "thread: txn 1 start"
Foo.transaction do
Foo.first(:id => 1)
log "thread: txn 2 start"
Foo.transaction do
begin
Foo.first(:id => 1)
rescue Exception => e
log "ERROR: #{e.inspect} (#{e.backtrace})"
exit!
end
end
log "thread: txn 2 end"
end
log "thread: txn 1 end"
cv.signal
end
end
while true
$FOO or mutex.synchronize { cv.wait(mutex) } and $FOO = true
log "main: get"
begin
Bar.first(:id => 1)
rescue Exception => e
log "ERROR: #{e.inspect} (#{e.backtrace})"
exit!
end
end
$ ruby bar.rb
starting
thread: txn 1 start
thread: txn 2 start
thread: txn 2 end
thread: txn 1 end
main: get
thread: txn 1 start
ERROR: #<ArgumentError: Field-count mismatch. Expected 3 fields, but the query yielded 1> (./common/gems/dm-do-
adapter.git/lib/dm-do-adapter/adapter.rb:145:in `execute_reader'./common/gems/dm-do-adapter.git/lib/dm-do-
adapter/adapter.rb:145:in `read'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:268:in
`with_connection'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:141:in `read'./common/gems/dm-core.git/lib/dm-
core/repository.rb:162:in `read'./common/gems/dm-core.git/lib/dm-core/model.rb:370:in `first'bar.rb:80)
$ ruby bar.rb
starting
thread: txn 1 start
thread: txn 2 start
thread: txn 2 end
thread: txn 1 end
main: get
thread: txn 1 start
ERROR: #<DataObjects::SQLError: Lost connection to MySQL server during query (code: 2013, sql state: HY000, query: SELECT
`id`, `dongs`, `balls` FROM `bars` WHERE `id` = 1 ORDER BY `id` LIMIT 1, uri: mysql://localhost/test)> (./common/gems/dm-do-
adapter.git/lib/dm-do-adapter/adapter.rb:145:in `execute_reader'./common/gems/dm-do-adapter.git/lib/dm-do-
adapter/adapter.rb:145:in `read'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:268:in
`with_connection'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:141:in `read'./common/gems/dm-core.git/lib/dm-
core/repository.rb:162:in `read'./common/gems/dm-core.git/lib/dm-core/model.rb:370:in `first'bar.rb:76)
$ ruby bar.rb
starting
thread: txn 1 start
thread: txn 2 start
thread: txn 2 end
thread: txn 1 end
main: get
thread: txn 1 start
ERROR: #<NoMethodError: undefined method `close' for nil:NilClass> (./common/gems/dm-do-adapter.git/lib/dm-do-
adapter/adapter.rb:152:in `read'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:268:in
`with_connection'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:141:in `read'./common/gems/dm-core.git/lib/dm-
core/repository.rb:162:in `read'./common/gems/dm-core.git/lib/dm-core/model.rb:370:in `first'bar.rb:75)
$ ruby bar.rb
starting
thread: txn 1 start
thread: txn 2 start
thread: txn 2 end
thread: txn 1 end
main: get
thread: txn 1 start
./common/gems/do.git/data_objects/lib/data_objects/transaction.rb:58:in `execute_non_query': Bad file descriptor (Errno::EBADF)
from ./common/gems/do.git/data_objects/lib/data_objects/transaction.rb:58:in `run'
from ./common/gems/do.git/data_objects/lib/data_objects/transaction.rb:39:in `begin'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:288:in `send'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:288:in `do_adapter'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:325:in `begin_adapter'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:250:in `send'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:250:in `each_adapter'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:249:in `each_key'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:249:in `each_adapter'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:109:in `begin'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:130:in `commit'
from ./common/gems/dm-transactions.git/lib/dm-transactions.rb:373:in `transaction'
from bar.rb:47
from bar.rb:41:in `initialize'
from bar.rb:41:in `new'
from bar.rb:41
- Ruby 1.8.7 p174 (OSX) and REE 2010.02 (Linux)
- DM *EDGE* (dm-core, dm-transactions)
- DO *EDGE*
- MySQL Server 5.x
Bugs:
- do_mysql cCommand_execute_reader is expected by dm-do-adapter to always return a result.
- There is one case where it returns Qnil, but the error is obscured at the DM level by dm-do-adapter's ensure block
ignoring the exception, but firing one of its own (should be NoMethodError of nil#next!, instead you get NoMethodError of
nil#close).
- When it returns Qnil, I think it's because the connection was dropped, but mysql_errno/mysql_error are empty. This
suggests that some undiscovered error condition in DM's invocation of DO lurks (but it's not clear who should have
responsibility for defending against getting into this condition in the first place).
diff --git a/lib/dm-do-adapter/adapter.rb b/lib/dm-do-adapter/adapter.rb
index 0bd53cc..93fc418 100644
--- a/lib/dm-do-adapter/adapter.rb
+++ b/lib/dm-do-adapter/adapter.rb
@@ -240,13 +240,16 @@ module DataMapper
#
# @api semipublic
def open_connection
- DataObjects::Connection.new(normalized_uri)
+ foo = DataObjects::Connection.new(normalized_uri)
+ warn "[#{Thread.current.object_id}] DO open_connection = #{foo.object_id}"
+ foo
end
# Takes connection and closes it
#
# @api semipublic
def close_connection(connection)
+ warn "[#{Thread.current.object_id}] DO close_connection(#{connection.object_id}) (current = #{connection.object_id})"
connection.close if connection.respond_to?(:close)
end
end
diff --git a/lib/dm-transactions/adapters/dm-do-adapter.rb b/lib/dm-transactions/adapters/dm-do-adapter.rb
index d6dffb9..0b0b98f 100644
--- a/lib/dm-transactions/adapters/dm-do-adapter.rb
+++ b/lib/dm-transactions/adapters/dm-do-adapter.rb
@@ -66,11 +66,14 @@ module DataMapper
# @api semipublic
def open_connection
- current_connection || super
+ foo = current_connection || super
+ warn "[#{Thread.current.object_id}] TXN open_connection = #{foo.object_id} (current = #{current_connection.object_id})"
+ foo
end
# @api semipublic
def close_connection(connection)
+ warn "[#{Thread.current.object_id}] TXN close_connection(#{connection.object_id}) (current = #{current_connection.object_id})
super unless current_connection.equal?(connection)
end
end
diff --git a/data_objects/lib/data_objects/pooling.rb b/data_objects/lib/data_objects/pooling.rb
index 28fa9d4..421ac5a 100644
--- a/data_objects/lib/data_objects/pooling.rb
+++ b/data_objects/lib/data_objects/pooling.rb
@@ -190,21 +190,31 @@ module DataObjects
end
end
end until instance
+ warn "[#{Thread.current.object_id}] POOL: acquire #{instance.object_id}"
+ _show_state
instance
end
def release(instance)
lock.synchronize do
+ warn "[#{Thread.current.object_id}] POOL: release #{instance.object_id}"
instance.instance_variable_set(:@__allocated_in_pool, Time.now)
@used.delete(instance.object_id)
- @available.push(instance)
+ @available.push(instance) unless @available.include?(instance)
+ _show_state
wait.signal
end
nil
end
+ def _show_state
+ warn "POOL: available = #{@available.map{|o| o.object_id}.join(',')}"
+ warn "POOL: used = #{@used.keys.join(',')}"
+ end
+
def delete(instance)
lock.synchronize do
+ warn "[#{Thread.current.object_id}] POOL: delete #{instance.object_id}"
instance.instance_variable_set(:@__pool, nil)
@used.delete(instance.object_id)
wait.signal
$ ruby bar.rb
[2148278700] POOL: acquire 2162530000
[2148278700] DO open_connection = 2162530000
[2148278700] TXN open_connection = 2162530000 (current = 4)
[2148278700] TXN close_connection(2162530000) (current = 4)
[2148278700] DO close_connection(2162530000) (current = 2162530000)
[2148278700] POOL: release 2162530000
[2148278700] POOL: acquire 2162530000
[2148278700] DO open_connection = 2162530000
[2148278700] TXN open_connection = 2162530000 (current = 4)
[2148278700] TXN close_connection(2162530000) (current = 4)
[2148278700] DO close_connection(2162530000) (current = 2162530000)
[2148278700] POOL: release 2162530000
[2148278700] POOL: acquire 2162530000
[2148278700] DO open_connection = 2162530000
[2148278700] TXN open_connection = 2162530000 (current = 4)
[2148278700] POOL: acquire 2162523280
[2148278700] DO open_connection = 2162523280
[2148278700] TXN open_connection = 2162523280 (current = 4)
[2148278700] TXN close_connection(2162523280) (current = 4)
[2148278700] DO close_connection(2162523280) (current = 2162523280)
[2148278700] POOL: release 2162523280
[2148278700] POOL: acquire 2162523280
[2148278700] DO open_connection = 2162523280
[2148278700] TXN open_connection = 2162523280 (current = 4)
[2148278700] TXN close_connection(2162523280) (current = 4)
[2148278700] DO close_connection(2162523280) (current = 2162523280)
[2148278700] POOL: release 2162523280
[2148278700] TXN close_connection(2162530000) (current = 4)
[2148278700] DO close_connection(2162530000) (current = 2162530000)
[2148278700] POOL: release 2162530000
[2148278700] POOL: acquire 2162530000
[2148278700] DO open_connection = 2162530000
[2148278700] TXN open_connection = 2162530000 (current = 4)
[2148278700] TXN close_connection(2162530000) (current = 4)
[2148278700] DO close_connection(2162530000) (current = 2162530000)
[2148278700] POOL: release 2162530000
[2148278700] POOL: acquire 2162530000
[2148278700] DO open_connection = 2162530000
[2148278700] TXN open_connection = 2162530000 (current = 4)
[2148278700] TXN close_connection(2162530000) (current = 4)
[2148278700] DO close_connection(2162530000) (current = 2162530000)
[2148278700] POOL: release 2162530000
[2148278700] POOL: acquire 2162530000
[2148278700] DO open_connection = 2162530000
[2148278700] TXN open_connection = 2162530000 (current = 4)
[2148278700] TXN close_connection(2162530000) (current = 4)
[2148278700] DO close_connection(2162530000) (current = 2162530000)
[2148278700] POOL: release 2162530000
[2148278700] starting
[2162514260] thread: txn 1 start
[2162514260] POOL: acquire 2162530000
[2162514260] TXN open_connection = 2162530000 (current = 2162530000)
[2162514260] TXN close_connection(2162530000) (current = 2162530000)
[2162514260] thread: txn 2 start
[2162514260] TXN open_connection = 2162530000 (current = 2162530000)
[2162514260] TXN close_connection(2162530000) (current = 2162530000)
[2162514260] POOL: release 2162530000
[2162514260] thread: txn 2 end
[2162514260] POOL: release 2162530000
[2162514260] thread: txn 1 end
[2148278700] main: get
[2148278700] POOL: acquire 2162530000
[2148278700] DO open_connection = 2162530000
[2148278700] TXN open_connection = 2162530000 (current = 4)
[2162514260] thread: txn 1 start
[2162514260] POOL: acquire 2162530000
[2148278700] TXN close_connection(2162530000) (current = 4)
[2148278700] DO close_connection(2162530000) (current = 2162530000)
[2148278700] POOL: release 2162530000
[2148278700] ERROR: #<NoMethodError: undefined method `close' for nil:NilClass> (./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:152:in `read'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:271:in `with_connection'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:141:in `read'./common/gems/dm-core.git/lib/dm-core/repository.rb:162:in `read'./common/gems/dm-core.git/lib/dm-core/model.rb:370:in `first'bar.rb:81)
$ ruby bar.rb
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used =
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used =
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2148278700] POOL: acquire 2162521140
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162521140
[2148278700] TXN open_connection = 2162521140 (current = 4)
[2148278700] TXN close_connection(2162521140) (current = 4)
[2148278700] DO close_connection(2162521140) (current = 2162521140)
[2148278700] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] POOL: acquire 2162521140
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162521140
[2148278700] TXN open_connection = 2162521140 (current = 4)
[2148278700] TXN close_connection(2162521140) (current = 4)
[2148278700] DO close_connection(2162521140) (current = 2162521140)
[2148278700] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2148278700] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2148278700] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2148278700] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2148278700] starting
[2162510120] thread: txn 1 start
[2162510120] current transactions = nil
[2162510120] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] TXN open_connection = 2162528760 (current = 2162528760)
[2162510120] TXN close_connection(2162528760) (current = 2162528760)
[2162510120] thread: txn 2 start
[2162510120] TXN open_connection = 2162528760 (current = 2162528760)
[2162510120] TXN close_connection(2162528760) (current = 2162528760)
[2162510120] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2162510120] thread: txn 2 end
[2162510120] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2162510120] thread: txn 1 end
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] thread: txn 1 start
[2162510120] current transactions = {2162591540=>[]}
[2162510120] POOL: acquire 2162521140
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2162510120] thread: txn 2 start
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 2 end
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 1 end
[2162510120] thread: txn 1 start
[2162510120] current transactions = {2162591540=>[]}
[2162510120] POOL: acquire 2162521140
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2162510120] thread: txn 2 start
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 2 end
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 1 end
[2162510120] thread: txn 1 start
[2162510120] current transactions = {2162591540=>[]}
[2162510120] POOL: acquire 2162521140
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2162510120] thread: txn 2 start
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 2 end
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 1 end
[2162510120] thread: txn 1 start
[2162510120] current transactions = {2162591540=>[]}
[2162510120] POOL: acquire 2162521140
POOL: available =
POOL: used = 2162528760,2162521140
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2162510120] thread: txn 2 start
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 2 end
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162521140,2162528760
POOL: used =
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available = 2162521140
POOL: used = 2162528760
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] POOL: release 2162521140
POOL: available = 2162521140
POOL: used = 2162528760
[2162510120] thread: txn 1 end
[2162510120] thread: txn 1 start
[2162510120] current transactions = {2162591540=>[]}
[2162510120] POOL: acquire 2162521140
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2162510120] thread: txn 2 start
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN open_connection = 2162521140 (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2148278700] POOL: acquire 2162528760
POOL: available =
POOL: used = 2162528760,2162521140
[2148278700] DO open_connection = 2162528760
[2148278700] TXN open_connection = 2162528760 (current = 4)
[2162510120] TXN close_connection(2162521140) (current = 2162521140)
[2148278700] TXN close_connection(2162528760) (current = 4)
[2148278700] DO close_connection(2162528760) (current = 2162528760)
[2148278700] POOL: release 2162528760
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] main: get
[2162510120] POOL: release 2162521140
POOL: available = 2162528760,2162521140
POOL: used =
[2162510120] thread: txn 2 end
[2148278700] POOL: acquire 2162521140
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] DO open_connection = 2162521140
[2148278700] TXN open_connection = 2162521140 (current = 4)
[2162510120] POOL: release 2162521140
POOL: available = 2162528760,2162521140
POOL: used =
[2162510120] thread: txn 1 end
[2162510120] thread: txn 1 start
[2162510120] current transactions = {2162591540=>[]}
[2162510120] POOL: acquire 2162521140
POOL: available = 2162528760
POOL: used = 2162521140
[2148278700] TXN close_connection(2162521140) (current = 4)
[2148278700] DO close_connection(2162521140) (current = 2162521140)
[2148278700] POOL: release 2162521140
POOL: available = 2162528760,2162521140
POOL: used =
[2148278700] ERROR: #<NoMethodError: undefined method `close' for nil:NilClass> (./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:152:in `read'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:271:in `with_connection'./common/gems/dm-do-adapter.git/lib/dm-do-adapter/adapter.rb:141:in `read'./common/gems/dm-core.git/lib/dm-core/repository.rb:162:in `read'./common/gems/dm-core.git/lib/dm-core/model.rb:370:in `first'bar.rb:81)
$
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment