Dead DB connection not picked up correctly

[jrgns]

Complete Description of Issue

When a system sits idle for long, the first couple of queries fail with the error posted below. It looks like the TinyTDS adapter doesn't recognize the dead connection properly. A previous fix for this was attempted in this commit, but it doesn't seem to have fixed it.

Simplest Possible Self-Contained Example Showing the Bug

require 'sequel'
require 'logger'
DB = Sequel.connect(ENV['DATABASE_URL'])
DB.extension(:connection_validator)
DB.loggers << Logger.new($stdout)
DB[:table].first # Successful
# Externally kill the connection to the DB
DB[:table].first # Reports the error below

/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/adapters/tinytds.rb:73: warning: TinyTds: dbsqlsend() returned FAIL.
Traceback (most recent call last):
       16: from /home/aex/.rvm/gems/ruby-2.7.0/bin/irb:23:in `<main>'
       15: from /home/aex/.rvm/gems/ruby-2.7.0/bin/irb:23:in `load'
       14: from /home/aex/.rvm/rubies/ruby-2.7.0/lib/ruby/gems/2.7.0/gems/irb-1.2.1/exe/irb:11:in `<top (required)>'
       13: from (irb):9
       12: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/dataset/actions.rb:208:in `first'
       11: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/dataset/actions.rb:693:in `single_record'
       10: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/dataset/actions.rb:705:in `single_record!'
        9: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/dataset/actions.rb:950:in `with_sql_first'
        8: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/dataset/actions.rb:942:in `with_sql_each'
        7: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/adapters/tinytds.rb:214:in `fetch_rows'
        6: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/dataset/actions.rb:1089:in `execute'
        5: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/adapters/tinytds.rb:46:in `execute'
        4: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/database/connecting.rb:270:in `synchronize'
        3: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/connection_pool/threaded.rb:92:in `hold'
        2: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/adapters/tinytds.rb:77:in `block in execute'
        1: from /home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.32.0/lib/sequel/adapters/tinytds.rb:217:in `block in fetch_rows'
NoMethodError (undefined method `fields' for false:FalseClass)

Full Backtrace of Exception (if any)

undefined method `each' for false:FalseClass (NoMethodError)
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/adapters/tinytds.rb:153:in `block in log_connection_execute'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/database/logging.rb:43:in `log_connection_yield'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/adapters/tinytds.rb:153:in `log_connection_execute'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/database/connecting.rb:290:in `valid_connection?'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/extensions/connection_validator.rb:104:in `block in acquire'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/extensions/connection_validator.rb:100:in `times'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/extensions/connection_validator.rb:100:in `acquire'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/connection_pool/sharded_threaded.rb:129:in `hold'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/database/connecting.rb:270:in `synchronize'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/adapters/tinytds.rb:250:in `literal_string_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/sql.rb:82:in `literal_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/sql.rb:408:in `complex_expression_sql_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/adapters/shared/mssql.rb:552:in `complex_expression_sql_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/model/associations.rb:2855:in `complex_expression_sql_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/sql.rb:112:in `to_s_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/sql.rb:1249:in `literal_expression_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/sql.rb:89:in `literal_append'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/sql.rb:1495:in `select_where_sql'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/sql.rb:248:in `select_sql'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/adapters/utils/emulate_offset_with_row_number.rb:22:in `select_sql'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/adapters/shared/mssql.rb:665:in `select_sql'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/actions.rb:705:in `single_record!'
/home/aex/fno-interface-stage/vendor/bundle/ruby/2.7.0/gems/sequel-5.31.0/lib/sequel/dataset/actions.rb:245:in `first'

SQL Log (if any)

NoMethodError: undefined method `each' for false:FalseClass: (conn: 54300, server: EVOTEL) SELECT NULL

[jeremyevans]

This appears to be a bug in TinyTDS that should be filed upstream. TinyTDS::Client#execute should not be returning false. If you look at the example code in the TinyTDS README (https://github.com/rails-sqlserver/tiny_tds/blob/master/README.md), you'll see that they are not checking whether the execute calls return a false value. It would be appropriate for TinyTDS to raise an exception in this case, not to warn and return false.

I'm going to close this now. Please file an issue upstream (https://github.com/rails-sqlserver/tiny_tds/issues). If the TinyTDS maintainers respond that the current behavior is expected and not a bug (unlikely), then I can reopen this and add a workaround.

[jrgns]

Will do, thanx.

[jrgns]

@jeremyevans there's been no response, but I see the activerecord-sqlserver-adapter project has added a workaround: rails-sqlserver/activerecord-sqlserver-adapter#818

[jeremyevans]

I don't want to add code like that to Sequel unless the TinyTDS developers confirm that the current TinyTDS behavior is desired and will not be fixed.

[jrgns]

A workaround extension until the issue is fixed upstream:

# frozen_string_literal: true

module Sequel
  module TinyTdsChecker
    def disconnect_error?(exception, opts)
      super ||
        ((exception.is_a?(NoMethodError) && /\A(undefined method `each' for false:FalseClass)/.match(exception.message))) ||
        ((exception.is_a?(Sequel::DatabaseDisconnectError) && /\A(DBPROCESS is dead or not enabled|Write to the server failed)/.match(exception.message)))
    end
  end

  Sequel::Database.register_extension(:tiny_tds_checker, Sequel::TinyTdsChecker)
end

[jrgns]

@jeremyevans digging up old cows here, but the extension I posted above stopped working (or never worked at all?).

The extension gets registered, but the disconnect_error? method is never called. Any guidance on what might be the issue?

[jeremyevans]

tiny_tds still hasn't fixed the upstream bug resulting in the NoMethodError. The handling of DatabaseDisconnectError inside disconnect_error? doesn't make sense, as disconnect_error? determines whether the underlying exception should be raised as a DatabaseDisconnectError.

In terms of the extension, it's only going to be called if you do DB.extension :tiny_tds_checker. Registering an extension does not activate it automatically.

[jrgns]

@jeremyevans I do the required DB.extension :tiny_tds_checker to enable the extension too.