TinyTDS timeout on network failure of open connection

ar_request.2.timeout_rb.rb

require 'active_record'

ActiveRecord::Base.establish_connection(
  :host => "ltwpeter-vm-w7",
  :adapter => "sqlserver",
  :mode => "odbc",
  :dsn => "ltwpeter_vm_w7",
  :username => "aw_web",
  :password => "aw_web8245",
  :database => "AdventureWorks"
)
SQL = ActiveRecord::Base
start_time = nil
begin
  start_time = Time.now
  puts "Starting ActiveRecord/SqlServer request"
  rows = SQL.connection.select_all("select count(column_name) as 'normal_count' from information_schema.columns")
  puts rows.inspect

  puts "Now pausing VirtualBox VM... "
  puts %x/ VBoxManage controlvm "Windows 7" pause /
  sleep 1
  puts "Then execute the request again w/ Timeout.rb::timeout() ..."
  puts "Start time #{start_time}"
  timeout(5) do
    rows = SQL.connection.select_all("select count(column_name) as 'timeout_count' from information_schema.columns")
    puts rows.inspect
  end

rescue Timeout::Error => time_e
  puts time_e.inspect
rescue Errno::ETIMEDOUT => etimeout
  puts etimeout.inspect
rescue Exception => e
  puts e.inspect
ensure
  puts "End  time #{Time.now} "
  puts "Total time for SQL request: #{start_time.nil? ? "error" : Time.now - start_time} "
  sleep 1
  puts "Now resuming VirtualBox VM... "
  puts %x/ VBoxManage controlvm "Windows 7" resume /
end
# # Total time for reqeust to 192.168.12.12: 74.629005

ar_request.3.system_timer.rb

require 'active_record'
require 'system_timer'

ActiveRecord::Base.establish_connection(
  :host => "ltwpeter-vm-w7",
  :adapter => "sqlserver",
  :mode => "odbc",
  :dsn => "ltwpeter_vm_w7",
  :username => "aw_web",
  :password => "aw_web8245",
  :database => "AdventureWorks"
)
SQL = ActiveRecord::Base
start_time = nil
begin
  start_time = Time.now
  puts "Starting ActiveRecord/SqlServer request"
  rows = SQL.connection.select_all("select count(column_name) as 'normal_count' from information_schema.columns")
  puts rows.inspect

  puts "Now pausing VirtualBox VM... "
  puts %x/ VBoxManage controlvm "Windows 7" pause /
  sleep 1
  puts "Then execute the request again with SystemTimer::timeout ..."
  puts "Start time #{start_time}"
  SystemTimer::timeout(5) do
    rows = SQL.connection.select_all("select count(column_name) as 'timeout_count' from information_schema.columns")
    puts rows.inspect
  end

rescue Timeout::Error => time_e
  puts time_e.inspect
rescue Errno::ETIMEDOUT => etimeout
  puts etimeout.inspect
rescue Exception => e
  puts e.inspect
ensure
  puts "End  time #{Time.now} "
  puts "Total time for SQL request: #{start_time.nil? ? "error" : Time.now - start_time} "
  sleep 1
  puts "Now resuming VirtualBox VM... "
  puts %x/ VBoxManage controlvm "Windows 7" resume /
end
# # Total time for reqeust to 192.168.12.12: 74.629005

ar_request.4.tinytds_timeout.rb

require 'active_record'
require 'tiny_tds'

ActiveRecord::Base.establish_connection(
  :host => "ltwpeter-vm-w7",
  :adapter => "sqlserver",
  :username => "aw_web",
  :password => "aw_web8245",
  :database => "AdventureWorks",
  :timeout => 5000 # blocking also occurs w/ :timeout => 5
)
SQL = ActiveRecord::Base
start_time = nil
begin
  start_time = Time.now
  puts "Starting ActiveRecord/SqlServer request"
  rows = SQL.connection.select_all("select count(column_name) as 'normal_count' from information_schema.columns")
  puts rows.inspect

  puts "Now pausing VirtualBox VM... "
  puts %x/ VBoxManage controlvm "Windows 7" pause /
  sleep 2
  puts "Start time #{start_time}"
  puts "Check for active Connection: #{SQL.connection.active?} "
  puts "Then execute the request again with TinyTDS timeout ..."
  rows = SQL.connection.select_all("select count(column_name) as 'timeout_count' from information_schema.columns")
  puts rows.inspect

rescue Timeout::Error => time_e
  puts time_e.inspect
rescue Errno::ETIMEDOUT => etimeout
  puts etimeout.inspect
rescue Exception => e
  puts e.inspect
ensure
  puts "End  time #{Time.now} "
  puts "Total time for SQL request: #{start_time.nil? ? "error" : Time.now - start_time} "
  sleep 1
  puts "Now resuming VirtualBox VM... "
  puts %x/ VBoxManage controlvm "Windows 7" resume /
end
# # Total time for reqeust to 192.168.12.12: 74.629005

Environment and config.sh

$ ruby -v
ruby 1.9.2p180 (2011-02-18 revision 30909) [x86_64-darwin10.8.0]

# Blocking also occurs with:
$ jruby -v
jruby 1.6.2 (ruby-1.8.7-p330) (2011-05-23 e2ea975) (Java HotSpot(TM) Client VM 1.6.0_26) [darwin-i386-java]

$ gem list

*** LOCAL GEMS ***

activemodel (3.0.9)
activerecord (3.0.9)
activerecord-sqlserver-adapter (3.0.15)
activesupport (3.0.9)
arel (2.0.10)
builder (2.1.2)
bundler (1.0.0.rc.5)
i18n (0.5.0)
rake (0.9.2)
rdoc (3.8)
tiny_tds (0.4.5)
tzinfo (0.3.29)


[05:24:19][~/ruby/timeout-hoedown {ruby-1.9.2-p180}]
$ VBoxManage showvminfo "Windows 7"
Name:            Windows 7
Guest OS:        Windows 7
UUID:            20be29ba-c226-4720-ba78-0b782aacc83d
Config file:     /Users/peterfitzgibbons/Library/VirtualBox/Machines/Windows 7/Windows 7.xml
Snapshot folder: /Users/peterfitzgibbons/Library/VirtualBox/Machines/Windows 7/Snapshots
Log folder:      /Users/peterfitzgibbons/Library/VirtualBox/Machines/Windows 7/Logs
Hardware UUID:   20be29ba-c226-4720-ba78-0b782aacc83d
Memory size:     1283MB
Page Fusion:     off
VRAM size:       128MB
CPU exec cap:    100%
HPET:            off
Chipset:         piix3
Firmware:        BIOS
Number of CPUs:  1
Synthetic Cpu:   off
CPUID overrides: None
Boot menu mode:  message and menu
Boot Device (1): Floppy
Boot Device (2): DVD
Boot Device (3): HardDisk
Boot Device (4): Not Assigned
ACPI:            on
IOAPIC:          off
PAE:             off
Time offset:     0 ms
RTC:             local time
Hardw. virt.ext: on
Hardw. virt.ext exclusive: off
Nested Paging:   on
Large Pages:     off
VT-x VPID:       on
State:           paused (since 2011-07-28T10:19:16.228000000)
Monitor count:   1
3D Acceleration: on
2D Video Acceleration: on
Teleporter Enabled: off
Teleporter Port: 0
Teleporter Address: 
Teleporter Password: 
Storage Controller Name (0):            IDE Controller
Storage Controller Type (0):            PIIX4
Storage Controller Instance Number (0): 0
Storage Controller Max Port Count (0):  2
Storage Controller Port Count (0):      2
Storage Controller Bootable (0):        on
Storage Controller Name (1):            SATA Controller
Storage Controller Type (1):            IntelAhci
Storage Controller Instance Number (1): 0
Storage Controller Max Port Count (1):  30
Storage Controller Port Count (1):      1
Storage Controller Bootable (1):        on
IDE Controller (1, 0): /Applications/VirtualBox.app/Contents/MacOS/VBoxGuestAdditions.iso (UUID: 3df3ca91-c84f-41df-b8ba-0547c88d33cd)
SATA Controller (0, 0): /Users/peterfitzgibbons/Library/VirtualBox/Machines/Windows 7/Snapshots/{f9b9d192-e0a3-4ba0-b65e-db6db0be086e}.vdi (UUID: f9b9d192-e0a3-4ba0-b65e-db6db0be086e)
NIC 1:           MAC: 0800274B47ED, Attachment: NAT, Cable connected: on, Trace: off (file: none), Type: 82540EM, Reported speed: 0 Mbps, Boot priority: 0, Promisc Policy: deny
NIC 1 Settings:  MTU: 0, Socket (send: 64, receive: 64), TCP Window (send:64, receive: 64)
NIC 2:           MAC: 08002740CCA2, Attachment: Host-only Interface 'vboxnet0', Cable connected: on, Trace: off (file: none), Type: 82540EM, Reported speed: 0 Mbps, Boot priority: 0, Promisc Policy: deny
NIC 3:           disabled
NIC 4:           disabled
NIC 5:           disabled
NIC 6:           disabled
NIC 7:           disabled
NIC 8:           disabled
Pointing Device: PS/2 Mouse
Keyboard Device: PS/2 Keyboard
UART 1:          disabled
UART 2:          disabled
Audio:           enabled (Driver: CoreAudio, Controller: AC97)
Clipboard Mode:  Bidirectional
Video mode:      728x829x32
VRDE:            disabled
USB:             enabled

USB Device Filters:

<none>

Available remote USB devices:

<none>

Currently Attached USB Devices:

<none>

Shared folders:  <none>

VRDE Connection:    not active
Clients so far:     0

Guest:

Configured memory balloon size:      0 MB
OS type:                             Windows7
Additions run level:                 2
Additions version:                   3.2.8 r64453


Guest Facilities:

Facility "VirtualBox Base Driver": active/running (last update: 2011/07/28 01:59:23 UTC)
Facility "VirtualBox System Service": active/running (last update: 2011/07/28 02:00:20 UTC)
Facility "Seamless Mode": active/running (last update: 2011/07/28 02:07:31 UTC)
Facility "Graphics Mode": active/running (last update: 2011/07/28 02:07:31 UTC)

Snapshots:

   Name: Windows 7 Base (UUID: cd1c2aa3-d136-49a6-97b7-7e71da2e9264)
      Name: Sql2008 Express installed (UUID: 46d591d6-10fc-4e46-9bfb-f47cb5a44c17) *

Example Run.sh

$ ruby -rubygems ar_request.4.tinytds_timeout.rb 
Starting ActiveRecord/SqlServer request
[{"normal_count"=>725}]
Now pausing VirtualBox VM... 

Then execute the request again with TinyTDS timeout ...
Start time 2011-07-28 05:11:14 -0500
#<ActiveRecord::LostConnection: TinyTds::Error: DBPROCESS is dead or not enabled: select count(column_name) as 'timeout_count' from information_schema.columns>
End  time 2011-07-28 05:16:25 -0500 
Total time for SQL request: 311.441423 
Now resuming VirtualBox VM... 

$