diff --git a/CHANGELOG.md b/CHANGELOG.md index f6f12c63..594e4298 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,6 +1,7 @@ ## (unreleased) * Improve handling of network related timeouts +* Fix error reporting when preceded by info message ## 2.1.3 diff --git a/ext/tiny_tds/client.c b/ext/tiny_tds/client.c index 3619cf9a..a65208df 100644 --- a/ext/tiny_tds/client.c +++ b/ext/tiny_tds/client.c @@ -24,25 +24,25 @@ VALUE opt_escape_regex, opt_escape_dblquote; // Lib Backend (Helpers) -VALUE rb_tinytds_raise_error(DBPROCESS *dbproc, int is_message, int cancel, const char *error, const char *source, int severity, int dberr, int oserr) { +VALUE rb_tinytds_raise_error(DBPROCESS *dbproc, tinytds_errordata error) { VALUE e; GET_CLIENT_USERDATA(dbproc); - if (cancel && !dbdead(dbproc) && userdata && !userdata->closed) { + if (error.cancel && !dbdead(dbproc) && userdata && !userdata->closed) { userdata->dbsqlok_sent = 1; dbsqlok(dbproc); userdata->dbcancel_sent = 1; dbcancel(dbproc); } - e = rb_exc_new2(cTinyTdsError, error); - rb_funcall(e, intern_source_eql, 1, rb_str_new2(source)); - if (severity) - rb_funcall(e, intern_severity_eql, 1, INT2FIX(severity)); - if (dberr) - rb_funcall(e, intern_db_error_number_eql, 1, INT2FIX(dberr)); - if (oserr) - rb_funcall(e, intern_os_error_number_eql, 1, INT2FIX(oserr)); - - if (severity <= 10 && is_message) { + e = rb_exc_new2(cTinyTdsError, error.error); + rb_funcall(e, intern_source_eql, 1, rb_str_new2(error.source)); + if (error.severity) + rb_funcall(e, intern_severity_eql, 1, INT2FIX(error.severity)); + if (error.dberr) + rb_funcall(e, intern_db_error_number_eql, 1, INT2FIX(error.dberr)); + if (error.oserr) + rb_funcall(e, intern_os_error_number_eql, 1, INT2FIX(error.oserr)); + + if (error.severity <= 10 && error.is_message) { VALUE message_handler = userdata && userdata->message_handler ? userdata->message_handler : Qnil; if (message_handler && message_handler != Qnil && rb_respond_to(message_handler, intern_call) != 0) { rb_funcall(message_handler, intern_call, 1, e); @@ -57,6 +57,16 @@ VALUE rb_tinytds_raise_error(DBPROCESS *dbproc, int is_message, int cancel, cons // Lib Backend (Memory Management & Handlers) +static void push_userdata_error(tinytds_client_userdata *userdata, tinytds_errordata error) { + // reallocate memory for the array as needed + if (userdata->nonblocking_errors_size == userdata->nonblocking_errors_length) { + userdata->nonblocking_errors_size *= 2; + userdata->nonblocking_errors = realloc(userdata->nonblocking_errors, userdata->nonblocking_errors_size * sizeof(tinytds_errordata)); + } + + userdata->nonblocking_errors[userdata->nonblocking_errors_length] = error; + userdata->nonblocking_errors_length++; +} int tinytds_err_handler(DBPROCESS *dbproc, int severity, int dberr, int oserr, char *dberrstr, char *oserrstr) { static const char *source = "error"; @@ -105,6 +115,16 @@ int tinytds_err_handler(DBPROCESS *dbproc, int severity, int dberr, int oserr, c break; } + tinytds_errordata error_data = { + .is_message = 0, + .cancel = cancel, + .severity = severity, + .dberr = dberr, + .oserr = oserr + }; + strncpy(error_data.error, dberrstr, ERROR_MSG_SIZE); + strncpy(error_data.source, source, ERROR_MSG_SIZE); + /* When in non-blocking mode we need to store the exception data to throw it once the blocking call returns, otherwise we will segfault ruby since part @@ -116,27 +136,9 @@ int tinytds_err_handler(DBPROCESS *dbproc, int severity, int dberr, int oserr, c dbcancel(dbproc); userdata->dbcancel_sent = 1; } - - /* - If we've already captured an error message, don't overwrite it. This is - here because FreeTDS sends a generic "General SQL Server error" message - that will overwrite the real message. This is not normally a problem - because a ruby exception is normally thrown and we bail before the - generic message can be sent. - */ - if (!userdata->nonblocking_error.is_set) { - userdata->nonblocking_error.is_message = 0; - userdata->nonblocking_error.cancel = cancel; - strncpy(userdata->nonblocking_error.error, dberrstr, ERROR_MSG_SIZE); - strncpy(userdata->nonblocking_error.source, source, ERROR_MSG_SIZE); - userdata->nonblocking_error.severity = severity; - userdata->nonblocking_error.dberr = dberr; - userdata->nonblocking_error.oserr = oserr; - userdata->nonblocking_error.is_set = 1; - } - + push_userdata_error(userdata, error_data); } else { - rb_tinytds_raise_error(dbproc, 0, cancel, dberrstr, source, severity, dberr, oserr); + rb_tinytds_raise_error(dbproc, error_data); } return return_value; @@ -148,25 +150,31 @@ int tinytds_msg_handler(DBPROCESS *dbproc, DBINT msgno, int msgstate, int severi int is_message_an_error = severity > 10 ? 1 : 0; + tinytds_errordata error_data = { + .is_message = !is_message_an_error, + .cancel = is_message_an_error, + .severity = severity, + .dberr = msgno, + .oserr = msgstate + }; + strncpy(error_data.error, msgtext, ERROR_MSG_SIZE); + strncpy(error_data.source, source, ERROR_MSG_SIZE); + // See tinytds_err_handler() for info about why we do this if (userdata && userdata->nonblocking) { - if (!userdata->nonblocking_error.is_set) { - userdata->nonblocking_error.is_message = !is_message_an_error; - userdata->nonblocking_error.cancel = is_message_an_error; - strncpy(userdata->nonblocking_error.error, msgtext, ERROR_MSG_SIZE); - strncpy(userdata->nonblocking_error.source, source, ERROR_MSG_SIZE); - userdata->nonblocking_error.severity = severity; - userdata->nonblocking_error.dberr = msgno; - userdata->nonblocking_error.oserr = msgstate; - userdata->nonblocking_error.is_set = 1; - } + /* + In the case of non-blocking command batch execution we can receive multiple messages + (including errors). We keep track of those here so they can be processed once the + non-blocking call returns. + */ + push_userdata_error(userdata, error_data); if (is_message_an_error && !dbdead(dbproc) && !userdata->closed) { dbcancel(dbproc); userdata->dbcancel_sent = 1; } } else { - rb_tinytds_raise_error(dbproc, !is_message_an_error, is_message_an_error, msgtext, source, severity, msgno, msgstate); + rb_tinytds_raise_error(dbproc, error_data); } return 0; } @@ -204,7 +212,10 @@ static void rb_tinytds_client_reset_userdata(tinytds_client_userdata *userdata) userdata->dbsqlok_sent = 0; userdata->dbcancel_sent = 0; userdata->nonblocking = 0; - userdata->nonblocking_error.is_set = 0; + // the following is mainly done for consistency since the values are reset accordingly in nogvl_setup/cleanup. + // the nonblocking_errors array does not need to be freed here. That is done as part of nogvl_cleanup. + userdata->nonblocking_errors_length = 0; + userdata->nonblocking_errors_size = 0; } static void rb_tinytds_client_mark(void *ptr) { diff --git a/ext/tiny_tds/client.h b/ext/tiny_tds/client.h index 5e5c811f..dcd6087c 100644 --- a/ext/tiny_tds/client.h +++ b/ext/tiny_tds/client.h @@ -5,9 +5,9 @@ void init_tinytds_client(); #define ERROR_MSG_SIZE 1024 +#define ERRORS_STACK_INIT_SIZE 2 typedef struct { - short int is_set; int is_message; int cancel; char error[ERROR_MSG_SIZE]; @@ -25,7 +25,9 @@ typedef struct { RETCODE dbsqlok_retcode; short int dbcancel_sent; short int nonblocking; - tinytds_errordata nonblocking_error; + short int nonblocking_errors_length; + short int nonblocking_errors_size; + tinytds_errordata *nonblocking_errors; VALUE message_handler; } tinytds_client_userdata; @@ -40,7 +42,7 @@ typedef struct { rb_encoding *encoding; } tinytds_client_wrapper; -VALUE rb_tinytds_raise_error(DBPROCESS *dbproc, int is_message, int cancel, const char *error, const char *source, int severity, int dberr, int oserr); +VALUE rb_tinytds_raise_error(DBPROCESS *dbproc, tinytds_errordata error); // Lib Macros diff --git a/ext/tiny_tds/result.c b/ext/tiny_tds/result.c index 3b7ad7cb..8541c6b4 100644 --- a/ext/tiny_tds/result.c +++ b/ext/tiny_tds/result.c @@ -86,6 +86,9 @@ static void dbcancel_ubf(DBPROCESS *client) { static void nogvl_setup(DBPROCESS *client) { GET_CLIENT_USERDATA(client); userdata->nonblocking = 1; + userdata->nonblocking_errors_length = 0; + userdata->nonblocking_errors = malloc(ERRORS_STACK_INIT_SIZE * sizeof(tinytds_errordata)); + userdata->nonblocking_errors_size = ERRORS_STACK_INIT_SIZE; } static void nogvl_cleanup(DBPROCESS *client) { @@ -96,17 +99,25 @@ static void nogvl_cleanup(DBPROCESS *client) { Now that the blocking operation is done, we can finally throw any exceptions based on errors from SQL Server. */ - if (userdata->nonblocking_error.is_set) { - userdata->nonblocking_error.is_set = 0; - rb_tinytds_raise_error(client, - userdata->nonblocking_error.is_message, - userdata->nonblocking_error.cancel, - userdata->nonblocking_error.error, - userdata->nonblocking_error.source, - userdata->nonblocking_error.severity, - userdata->nonblocking_error.dberr, - userdata->nonblocking_error.oserr); + for (short int i = 0; i < userdata->nonblocking_errors_length; i++) { + tinytds_errordata error = userdata->nonblocking_errors[i]; + + // lookahead to drain any info messages ahead of raising error + if (!error.is_message) { + for (short int j = i; j < userdata->nonblocking_errors_length; j++) { + tinytds_errordata msg_error = userdata->nonblocking_errors[j]; + if (msg_error.is_message) { + rb_tinytds_raise_error(client, msg_error); + } + } + } + + rb_tinytds_raise_error(client, error); } + + free(userdata->nonblocking_errors); + userdata->nonblocking_errors_length = 0; + userdata->nonblocking_errors_size = 0; } static RETCODE nogvl_dbsqlok(DBPROCESS *client) { diff --git a/test/result_test.rb b/test/result_test.rb index 63649d4b..e40217f4 100644 --- a/test/result_test.rb +++ b/test/result_test.rb @@ -652,6 +652,48 @@ class ResultTest < TinyTds::TestCase assert_equal 1, messages.length, 'there should be one message after one print statement' assert_equal msg, m.message, 'message text' end + + it 'must raise an error preceded by a `print` message' do + messages.clear + action = lambda { @client.execute("EXEC tinytds_TestPrintWithError").do } + assert_raise_tinytds_error(action) do |e| + assert_equal 'hello', messages.first.message, 'message text' + + assert_equal "Error following print", e.message + assert_equal 16, e.severity + assert_equal 50000, e.db_error_number + end + end + + it 'calls the provided message handler for each of a series of `print` messages' do + messages.clear + @client.execute("EXEC tinytds_TestSeveralPrints").do + assert_equal ['hello 1', 'hello 2', 'hello 3'], messages.map { |e| e.message }, 'message list' + end + + it 'should flush info messages before raising error in cases of timeout' do + @client = new_connection timeout: 1, message_handler: Proc.new { |m| messages << m } + action = lambda { @client.execute("print 'hello'; waitfor delay '00:00:02'").do } + messages.clear + assert_raise_tinytds_error(action) do |e| + assert_match %r{timed out}i, e.message, 'ignore if non-english test run' + assert_equal 6, e.severity + assert_equal 20003, e.db_error_number + assert_equal 'hello', messages.first&.message, 'message text' + end + end + + it 'should print info messages before raising error in cases of timeout' do + @client = new_connection timeout: 1, message_handler: Proc.new { |m| messages << m } + action = lambda { @client.execute("raiserror('hello', 1, 1) with nowait; waitfor delay '00:00:02'").do } + messages.clear + assert_raise_tinytds_error(action) do |e| + assert_match %r{timed out}i, e.message, 'ignore if non-english test run' + assert_equal 6, e.severity + assert_equal 20003, e.db_error_number + assert_equal 'hello', messages.first&.message, 'message text' + end + end end it 'must not raise an error when severity is 10 or less' do @@ -770,4 +812,3 @@ def insert_and_select_datatype(datatype) end end - diff --git a/test/test_helper.rb b/test/test_helper.rb index fc364b42..66f56d1c 100644 --- a/test/test_helper.rb +++ b/test/test_helper.rb @@ -154,6 +154,8 @@ def load_current_schema loader.execute(drop_sql).do loader.execute(schema_sql).do loader.execute(sp_sql).do + loader.execute(sp_error_sql).do + loader.execute(sp_several_prints_sql).do loader.close true end @@ -168,7 +170,16 @@ def drop_sql_sybase ) DROP TABLE datatypes IF EXISTS( SELECT 1 FROM sysobjects WHERE type = 'P' AND name = 'tinytds_TestReturnCodes' - ) DROP PROCEDURE tinytds_TestReturnCodes| + ) DROP PROCEDURE tinytds_TestReturnCodes + IF EXISTS( + SELECT 1 FROM sysobjects WHERE type = 'P' AND name = 'tinytds_TestPrintWithError' + ) DROP PROCEDURE tinytds_TestPrintWithError + IF EXISTS( + SELECT 1 FROM sysobjects WHERE type = 'P' AND name = 'tinytds_TestPrintWithError' + ) DROP PROCEDURE tinytds_TestPrintWithError + IF EXISTS( + SELECT 1 FROM sysobjects WHERE type = 'P' AND name = 'tinytds_TestSeveralPrints' + ) DROP PROCEDURE tinytds_TestSeveralPrints| end def drop_sql_microsoft @@ -182,7 +193,15 @@ def drop_sql_microsoft IF EXISTS ( SELECT name FROM sysobjects WHERE name = 'tinytds_TestReturnCodes' AND type = 'P' - ) DROP PROCEDURE tinytds_TestReturnCodes| + ) DROP PROCEDURE tinytds_TestReturnCodes + IF EXISTS ( + SELECT name FROM sysobjects + WHERE name = 'tinytds_TestPrintWithError' AND type = 'P' + ) DROP PROCEDURE tinytds_TestPrintWithError + IF EXISTS ( + SELECT name FROM sysobjects + WHERE name = 'tinytds_TestSeveralPrints' AND type = 'P' + ) DROP PROCEDURE tinytds_TestSeveralPrints| end def sp_sql @@ -192,6 +211,21 @@ def sp_sql RETURN(420) | end + def sp_error_sql + %|CREATE PROCEDURE tinytds_TestPrintWithError + AS + PRINT 'hello' + RAISERROR('Error following print', 16, 1)| + end + + def sp_several_prints_sql + %|CREATE PROCEDURE tinytds_TestSeveralPrints + AS + PRINT 'hello 1' + PRINT 'hello 2' + PRINT 'hello 3'| + end + def find_value(id, column, query_options={}) query_options[:timezone] ||= :utc sql = "SELECT [#{column}] FROM [datatypes] WHERE [id] = #{id}"