Merge pull request #481 from bvogelzang/network-timeout-handling

Improve handling of network related timeouts

Author: bvogelzang

.travis.yml

@@ -14,9 +14,9 @@ rvm:
   - 2.7.0
 before_install:
   - docker info
+  - docker-compose up -d
   - sudo ./test/bin/install-openssl.sh
   - sudo ./test/bin/install-freetds.sh
-  - sudo ./test/bin/setup.sh
 install:
   - gem install bundler
   - bundle --version

CHANGELOG.md

@@ -1,5 +1,7 @@
 ## (unreleased)
 
+* Improve handling of network related timeouts
+
 ## 2.1.3
 
 * Removed old/unused appveyor config

README.md

@@ -110,7 +110,7 @@ Creating a new client takes a hash of options. For valid iconv encoding options,
 * :appname - Short string seen in SQL Servers process/activity window.
 * :tds_version - TDS version. Defaults to "7.3".
 * :login_timeout - Seconds to wait for login. Default to 60 seconds.
-* :timeout - Seconds to wait for a response to a SQL command. Default 5 seconds. Prior to 1.0rc5, FreeTDS was unable to set the timeout on a per-client basis, permitting only a global timeout value. This means that if you're using an older version, the timeout values for all clients will be overwritten each time you instantiate a new `TinyTds::Client` object. If you are using 1.0rc5 or later, all clients will have an independent timeout setting as you'd expect.
+* :timeout - Seconds to wait for a response to a SQL command. Default 5 seconds. Prior to 1.0rc5, FreeTDS was unable to set the timeout on a per-client basis, permitting only a global timeout value. This means that if you're using an older version, the timeout values for all clients will be overwritten each time you instantiate a new `TinyTds::Client` object. If you are using 1.0rc5 or later, all clients will have an independent timeout setting as you'd expect. Timeouts caused by network failure will raise a timeout error 1 second after the configured timeout limit is hit (see [#481](https://github.com/rails-sqlserver/tiny_tds/pull/481) for details).
 * :encoding - Any valid iconv value like CP1251 or ISO-8859-1. Default UTF-8.
 * :azure - Pass true to signal that you are connecting to azure.
 * :contained - Pass true to signal that you are connecting with a contained database user.
@@ -322,6 +322,10 @@ By default row caching is turned on because the SQL Server adapter for ActiveRec
 TinyTDS takes an opinionated stance on how we handle encoding errors. First, we treat errors differently on reads vs. writes. Our opinion is that if you are reading bad data due to your client's encoding option, you would rather just find `?` marks in your strings vs being blocked with exceptions. This is how things wold work via ODBC or SMS. On the other hand, writes will raise an exception. In this case we raise the SYBEICONVO/2402 error message which has a description of `Error converting characters into server's character set. Some character(s) could not be converted.`. Even though the severity of this message is only a `4` and TinyTDS will automatically strip/ignore unknown characters, we feel you should know that you are inserting bad encodings. In this way, a transaction can be rolled back, etc. Remember, any database write that has bad characters due to the client encoding will still be written to the database, but it is up to you rollback said write if needed. Most ORMs like ActiveRecord handle this scenario just fine.
 
 
+## Timeout Error Handling
+
+TinyTDS will raise a `TinyTDS::Error` when a timeout is reached based on the options supplied to the client. Depending on the reason for the timeout, the connection could be dead or alive. When db processing is the cause for the timeout, the connection should still be usable after the error is raised. When network failure is the cause of the timeout, the connection will be dead. If you attempt to execute another command batch on a dead connection you will see a `DBPROCESS is dead or not enabled` error. Therefore, it is recommended to check for a `dead?` connection before trying to execute another command batch.
+
 ## Binstubs
 
 The TinyTDS gem uses binstub wrappers which mirror compiled [FreeTDS Utilities](https://www.freetds.org/userguide/usefreetds.html) binaries. These native executables are usually installed at the system level when installing FreeTDS. However, when using MiniPortile to install TinyTDS as we do with Windows binaries, these binstubs will find and prefer local gem `exe` directory executables. These are the following binstubs we wrap.
@@ -419,17 +423,20 @@ First, clone the repo using the command line or your Git GUI of choice.
 $ git clone git@github.com:rails-sqlserver/tiny_tds.git
 ```
 
-After that, the quickest way to get setup for development is to use [Docker](https://www.docker.com/). Assuming you have [downloaded docker](https://www.docker.com/products/docker) for your platform and you have , you can run our test setup script.
+After that, the quickest way to get setup for development is to use [Docker](https://www.docker.com/). Assuming you have [downloaded docker](https://www.docker.com/products/docker) for your platform, you can use [docker-compose](https://docs.docker.com/compose/install/) to run the necessary containers for testing.
 
 ```shell
-$ ./test/bin/setup.sh
+$ docker-compose up -d
 ```
 
-This will download our SQL Server for Linux Docker image based from [microsoft/mssql-server-linux/](https://hub.docker.com/r/microsoft/mssql-server-linux/). Our image already has the `[tinytdstest]` DB and `tinytds` users created. Basically, it does the following.
+This will download our SQL Server for Linux Docker image based from [microsoft/mssql-server-linux/](https://hub.docker.com/r/microsoft/mssql-server-linux/). Our image already has the `[tinytdstest]` DB and `tinytds` users created. This will also download a [toxiproxy](https://github.com/shopify/toxiproxy) Docker image which we can use to simulate network failures for tests. Basically, it does the following.
 
 ```shell
+$ docker network create main-network
 $ docker pull metaskills/mssql-server-linux-tinytds
-$ docker run -p 1433:1433 -d metaskills/mssql-server-linux-tinytds
+$ docker run -p 1433:1433 -d --name sqlserver --network main-network metaskills/mssql-server-linux-tinytds
+$ docker pull shopify/toxiproxy
+$ docker run -p 8474:8474 -p 1234:1234 -d --name toxiproxy --network main-network shopify/toxiproxy
 ```
 
 If you are using your own database. Make sure to run these SQL commands as SA to get the test database and user installed.

docker-compose.yml

@@ -0,0 +1,22 @@
+version: '3'
+
+networks:
+  main-network:
+
+services:
+  mssql:
+    image: metaskills/mssql-server-linux-tinytds:2017-GA
+    container_name: sqlserver
+    ports:
+      - "1433:1433"
+    networks:
+      - main-network
+
+  toxiproxy:
+    image: shopify/toxiproxy
+    container_name: toxiproxy
+    ports:
+      - "8474:8474"
+      - "1234:1234"
+    networks:
+      - main-network

ext/tiny_tds/client.c

@@ -86,7 +86,13 @@ int tinytds_err_handler(DBPROCESS *dbproc, int severity, int dberr, int oserr, c
       but we don't ever want to automatically retry. Instead have the app
       decide what to do.
       */
-      return_value = INT_TIMEOUT;
+      if (userdata->timing_out) {
+        return INT_CANCEL;
+      }
+      else {
+        userdata->timing_out = 1;
+        return_value = INT_TIMEOUT;
+      }
       cancel = 1;
       break;
 
@@ -165,6 +171,33 @@ int tinytds_msg_handler(DBPROCESS *dbproc, DBINT msgno, int msgstate, int severi
   return 0;
 }
 
+/*
+Used by dbsetinterrupt -
+This gets called periodically while waiting on a read from the server
+Right now, we only care about cases where a read from the server is
+taking longer than the specified timeout and dbcancel is not working.
+In these cases we decide that we actually want to handle the interrupt
+*/
+static int check_interrupt(void *ptr) {
+  GET_CLIENT_USERDATA((DBPROCESS *)ptr);
+  return userdata->timing_out;
+}
+
+/*
+Used by dbsetinterrupt -
+This gets called if check_interrupt returns TRUE.
+Right now, this is only used in cases where a read from the server is
+taking longer than the specified timeout and dbcancel is not working.
+Return INT_CANCEL to abort the current command batch.
+*/
+static int handle_interrupt(void *ptr) {
+  GET_CLIENT_USERDATA((DBPROCESS *)ptr);
+  if (userdata->timing_out) {
+    return INT_CANCEL;
+  }
+  return INT_CONTINUE;
+}
+
 static void rb_tinytds_client_reset_userdata(tinytds_client_userdata *userdata) {
   userdata->timing_out = 0;
   userdata->dbsql_sent = 0;
@@ -381,6 +414,7 @@ static VALUE rb_tinytds_connect(VALUE self, VALUE opts) {
       }
     }
     dbsetuserdata(cwrap->client, (BYTE*)cwrap->userdata);
+    dbsetinterrupt(cwrap->client, check_interrupt, handle_interrupt);
     cwrap->userdata->closed = 0;
     if (!NIL_P(database) && (azure != Qtrue)) {
       dbuse(cwrap->client, StringValueCStr(database));

ext/tiny_tds/result.c

@@ -91,6 +91,7 @@ static void nogvl_setup(DBPROCESS *client) {
 static void nogvl_cleanup(DBPROCESS *client) {
   GET_CLIENT_USERDATA(client);
   userdata->nonblocking = 0;
+  userdata->timing_out = 0;
   /*
   Now that the blocking operation is done, we can finally throw any
   exceptions based on errors from SQL Server.

test/client_test.rb

@@ -68,6 +68,9 @@ class ClientTest < TinyTds::TestCase
   end
 
   describe 'With in-valid options' do
+    before(:all) do
+      init_toxiproxy
+    end
 
     it 'raises an argument error when no :host given and :dataserver is blank' do
       assert_raises(ArgumentError) { new_connection :dataserver => nil, :host => nil }
@@ -129,30 +132,46 @@ class ClientTest < TinyTds::TestCase
       end
     end
 
-    it 'must run this test to prove we account for dropped connections' do
-      skip
+    it 'raises TinyTds exception with tcp socket network failure' do
+      skip if ENV['CI'] && ENV['APPVEYOR_BUILD_FOLDER'] # only CI using docker
       begin
-        client = new_connection :login_timeout => 2, :timeout => 2
+        client = new_connection timeout: 2, port: 1234
         assert_client_works(client)
-        STDOUT.puts "Disconnect network!"
-        sleep 10
-        STDOUT.puts "This should not get stuck past 6 seconds!"
-        action = lambda { client.execute('SELECT 1 as [one]').each }
-        assert_raise_tinytds_error(action) do |e|
-          assert_equal 20003, e.db_error_number
-          assert_equal 6, e.severity
-          assert_match %r{timed out}i, e.message, 'ignore if non-english test run'
+        action = lambda { client.execute("waitfor delay '00:00:05'").do }
+
+        # Use toxiproxy to close the TCP socket after 1 second.
+        # We want TinyTds to execute the statement, hit the timeout configured above, and then not be able to use the network to cancel
+        # the network connection needs to close after the sql batch is sent and before the timeout above is hit
+        Toxiproxy[:sqlserver_test].toxic(:slow_close, delay: 1000).apply do
+          assert_raise_tinytds_error(action) do |e|
+            assert_equal 20003, e.db_error_number
+            assert_equal 6, e.severity
+            assert_match %r{timed out}i, e.message, 'ignore if non-english test run'
+          end
         end
       ensure
-        STDOUT.puts "Reconnect network!"
-        sleep 10
-        action = lambda { client.execute('SELECT 1 as [one]').each }
-        assert_raise_tinytds_error(action) do |e|
-          assert_equal 20047, e.db_error_number
-          assert_equal 1, e.severity
-          assert_match %r{dead or not enabled}i, e.message, 'ignore if non-english test run'
+        assert_new_connections_work
+      end
+    end
+
+    it 'raises TinyTds exception with dead connection network failure' do
+      skip if ENV['CI'] && ENV['APPVEYOR_BUILD_FOLDER'] # only CI using docker
+      begin
+        client = new_connection timeout: 2, port: 1234
+        assert_client_works(client)
+        action = lambda { client.execute("waitfor delay '00:00:05'").do }
+
+        # Use toxiproxy to close the network connection after 1 second.
+        # We want TinyTds to execute the statement, hit the timeout configured above, and then not be able to use the network to cancel
+        # the network connection needs to close after the sql batch is sent and before the timeout above is hit
+        Toxiproxy[:sqlserver_test].toxic(:timeout, timeout: 1000).apply do
+          assert_raise_tinytds_error(action) do |e|
+            assert_equal 20047, e.db_error_number
+            assert_includes [1,9], e.severity
+            assert_match %r{dead or not enabled}i, e.message, 'ignore if non-english test run'
+          end
         end
-        close_client(client)
+      ensure
         assert_new_connections_work
       end
     end

test/test_helper.rb

@@ -2,6 +2,7 @@
 require 'bundler' ; Bundler.require :development, :test
 require 'tiny_tds'
 require 'minitest/autorun'
+require 'toxiproxy'
 
 TINYTDS_SCHEMAS = ['sqlserver_2000', 'sqlserver_2005', 'sqlserver_2008', 'sqlserver_2014', 'sqlserver_azure', 'sybase_ase'].freeze
 
@@ -212,6 +213,25 @@ def rollback_transaction(client)
       client.execute("ROLLBACK TRANSACTION").do
     end
 
+    def init_toxiproxy
+      return if ENV['APPVEYOR_BUILD_FOLDER'] # only for CI using docker
+
+      # In order for toxiproxy to work for local docker instances of mssql, the containers must be on the same network
+      # and the host used below must match the mssql container name so toxiproxy knows where to proxy to.
+      # localhost from the perspective of toxiproxy's container is its own container an *not* the mssql container it needs to proxy to.
+      # docker-compose.yml handles this automatically for us. In instances where someone is using their own local mssql container they'll
+      # need to set up the networks manually and set TINYTDS_UNIT_HOST to their mssql container name
+      # For anything other than localhost just use the environment config
+      env_host = ENV['TINYTDS_UNIT_HOST_TEST'] || ENV['TINYTDS_UNIT_HOST'] || 'localhost'
+      host = ['localhost', '127.0.0.1', '0.0.0.0'].include?(env_host) ? 'sqlserver' : env_host
+      port = ENV['TINYTDS_UNIT_PORT'] || 1433
+      Toxiproxy.populate([
+        {
+          name: "sqlserver_test",
+          listen: "0.0.0.0:1234",
+          upstream: "#{host}:#{port}"
+        }
+      ])
+    end
   end
 end
-

tiny_tds.gemspec

@@ -26,4 +26,5 @@ Gem::Specification.new do |s|
   s.add_development_dependency 'rake-compiler-dock', '~> 1.0'
   s.add_development_dependency 'minitest', '~> 5.6'
   s.add_development_dependency 'connection_pool', '~> 2.2'
+  s.add_development_dependency 'toxiproxy', '~> 2.0.0'
 end