FreeTDS Development Group

[Gregory Holtorf <gregory.holtorf AT gmail.com>]

When calling ct_cancel in the freetds library, on unix, ct_cancel()
sometimes takes several minutes to run. This is bad because it usually
takes a few milliseconds to run. This bug works on freetds-0.91 and
freetds-0.64 In order to reproduce the bug, I needed to:

1. Run a select statement on a large table

2. The table has to contain nvarchar columns. varchar columns do not
trigger the bug.

3. The select statement must contain an order by clause


  select <nvarchar columns>

  from <table name>

  order by <nvarchar column>


After completing the select statement, call ct_cancel(). For instance,
before you make another select statement or when you log out.

  ct_cancel(m_pCtConnection, NULL, CS_CANCEL_ALL);


When I turn on logging I can see that after I call ct_cancel() for the last
time, it is followed by an absolutely huge number of packets received.  I
attached a log file, but I had to force quit the program or else the log
file ends up being several thousand megabytes long.

Is there a way to fix this issue? Is freetds unable to make select
statements on nvarchar columns or is it something I did in my code?


Thanks,

Greg

Attachment: freetds.log
Description: Binary data

#include <config.h>
#include <string.h>
#include <string>
#include <vector>

#include <stdio.h>
#include <ctpublic.h>
#include "tds_sysdep_private.h"
#include "ctlib.h"
#include "stdlib.h"


char USER[512];
char SERVER[512];
char PASSWORD[512];
char DATABASE[512];

int cslibmsg_cb_invoked = 0;
int clientmsg_cb_invoked = 0;
int servermsg_cb_invoked = 0;

int m_iNumRowCount = 0;
CS_INT m_iNumColumns = 0;
CS_INT m_iNumRowsAffected = 0;

struct COLINFO
{
	char *  dszValue;
	char    szColName[100+1];
	int     iDataType;
	int     iMaxDataLen;
	short   indp;   // oratypes.h:typedef   signed short    sb2;

};
std::vector<COLINFO> m_dColInfo;

CS_COMMAND    *m_pCtCommand;
CS_CONNECTION *m_pCtConnection;
CS_CONTEXT    *m_pCtContext;

CS_RETCODE
clientmsg_cb(CS_CONTEXT * context, CS_CONNECTION * connection, CS_CLIENTMSG * errmsg)
{
	clientmsg_cb_invoked++;
	fprintf(stderr, "\nOpen Client Message:\n");
	fprintf(stderr, "number %d layer %d origin %d severity %d number %d\n",
		errmsg->msgnumber,
		CS_LAYER(errmsg->msgnumber),
		CS_ORIGIN(errmsg->msgnumber), CS_SEVERITY(errmsg->msgnumber), CS_NUMBER(errmsg->msgnumber));
	fprintf(stderr, "msgstring: %s\n", errmsg->msgstring);
	fprintf(stderr, "osstring: %s\n", (errmsg->osstringlen > 0)
		? errmsg->osstring : "(null)");
	return CS_SUCCEED;
}

CS_RETCODE
servermsg_cb(CS_CONTEXT * context, CS_CONNECTION * connection, CS_SERVERMSG * srvmsg)
{
	servermsg_cb_invoked++;

	if (srvmsg->msgnumber == 5701 || srvmsg->msgnumber == 5703) {
		fprintf(stderr, "%s\n", srvmsg->text);
		return CS_SUCCEED;
	}
		
	fprintf(stderr, "%s Message %d severity %d state %d line %d:\n",
		srvmsg->svrnlen > 0? srvmsg->svrname : "Server", 
		srvmsg->msgnumber, srvmsg->severity, srvmsg->state, srvmsg->line);
	if (srvmsg->proclen > 0) 
		fprintf(stderr, "proc %s: ", srvmsg->proc);
	fprintf(stderr, "\t\"%s\"\n", srvmsg->text);

	return CS_SUCCEED;
}

bool ctlib_execsql(const char *pszFormat, ...)
{
	char sql[10000+1];
	va_list vaArgList;
	va_start(vaArgList, pszFormat);
	vsnprintf(sql, 10000, pszFormat, vaArgList);
	va_end  (vaArgList);
	
	enum {SANITY_MAX = 50*1024};
	CS_RETCODE ret, results_ret;
	CS_INT result_type;
	CS_INT num_cols, compute_id;

	CS_SMALLINT ind;

	m_iNumRowCount = 0;
	m_iNumColumns = 0;
	fprintf(stderr, "ctlib_execsql: %s \n", sql);
	
	for(size_t ii = 0; ii < m_dColInfo.size(); ++ii) {
		fprintf (stdout, "freeing Value():%s\n", m_dColInfo[ii].dszValue);
		delete[] m_dColInfo[ii].dszValue;
		m_dColInfo[ii].dszValue = NULL;
	}
	m_dColInfo.resize(0);
	
	if (m_pCtCommand == NULL) {
		return false;
	}
	
	int iRetriesLeft = 3;
	do {
		fprintf(stderr, "ctlib_execsql: clearing errors: ct_cancel()\n");
		ct_cancel(m_pCtConnection, NULL, CS_CANCEL_ALL);

		fprintf(stderr, "ctlib_execsql: ct_command()\n");
		if (ct_command (m_pCtCommand, CS_LANG_CMD, sql, CS_NULLTERM, CS_UNUSED) != CS_SUCCEED) {
			fprintf(stderr, "ct_command() failed\n");
			if (--iRetriesLeft > 0)
				continue;
			return false;
			
		}
		
		fprintf(stdout, "ctlib_execsql: ct_send()\n");
		ret = ct_send (m_pCtCommand);
		if (ret != CS_SUCCEED) {
			fprintf(stderr, "ct_send() failed with:%i\n", ret);
			if (--iRetriesLeft > 0)
				continue;
			return false;
		}
		break;
	} while(true);
	
	fprintf(stderr, "ctlib_execsql: ct_results() loop\n");
	while ((results_ret = ct_results (m_pCtCommand, &result_type)) == CS_SUCCEED) {
		fprintf(stdout, "ctlib_execsql: ct_results()\n");
		bool resultFound = false;
		
		switch ((int) result_type) {
		case CS_CMD_SUCCEED:
			fprintf(stdout, "ctlib_execsql: ct_results(%i,%i):CS_CMD_SUCCEED\n", results_ret, result_type);
			break;
		case CS_CMD_DONE:
			fprintf(stdout, "ctlib_execsql: ct_results(%i,%i):CS_CMD_DONE\n", results_ret, result_type);
			resultFound = true;
			break;
		case CS_STATUS_RESULT:
			fprintf(stdout, "ExecSql>ctlib_prepare_results>ct_results>CS_STATUS_RESULT(%d)", result_type);
			resultFound = true;
			break;
		case CS_END_RESULTS:
			fprintf(stdout, "ExecSql>ctlib_prepare_results>ct_results>CS_END_RESULTS(%d)", result_type);
			resultFound = true;
			break;
		case CS_CMD_FAIL:
			fprintf(stdout, "ct_results() result_type CS_CMD_FAIL.\n");
			return false;
		case CS_FAIL:
			fprintf(stdout, "ExecSql>ctlib_prepare_results>ct_results>CS_FAIL(%d)", result_type);
			return (false);
		case CS_CURSOR_RESULT:
			fprintf(stdout, "ExecSql>ctlib_prepare_results>ct_results>CS_CURSOR_RESULT(%d).\n"
							"Will act like CS_ROW_RESULTS.", result_type);
			//fall-through..
		case CS_ROW_RESULT:
			fprintf(stdout, "ctlib_execsql: ct_results(%i,%i):CS_ROW_RESULT\n", results_ret, result_type);
			resultFound = true;
			
			if (ct_res_info (m_pCtCommand, CS_NUMDATA, &num_cols, CS_UNUSED, NULL) != CS_SUCCEED) {
				fprintf(stderr, "ct_res_info() failed\n");
				return false;
			}
			
			if (num_cols <= 0) {
				fprintf(stderr, "num_cols = %d\n", num_cols);
				return false;
			}
			
			m_iNumColumns = num_cols;
			
			for (CS_INT iCol = 0; iCol < num_cols; iCol++)
			{
				fprintf(stderr, "ct_describe() column #%i \n", iCol);
				CS_DATAFMT datafmt;
				if (ct_describe (m_pCtCommand, iCol+1, &datafmt) != CS_SUCCEED) {
					fprintf(stderr, "ct_describe() failed\n");
					return false;
				}
				
				COLINFO pCol;
				pCol.iDataType   = datafmt.datatype;
				pCol.iMaxDataLen = 8000;
				pCol.indp        = 0;
				
				CS_INT datalength;
				datafmt.datatype  = CS_CHAR_TYPE;
				datafmt.format    = CS_FMT_NULLTERM;
				datafmt.maxlength = 8000;
				datafmt.count     = 1;
				datafmt.locale    = NULL;
				
				strncpy (pCol.szColName, (datafmt.namelen) ? datafmt.name : "", 100+1);
				pCol.dszValue  = new char[datafmt.maxlength + 1];
				
				fprintf(stderr, "ct_bind() column #%i \n", iCol);
				if (ct_bind (m_pCtCommand, iCol+1, &datafmt, pCol.dszValue, &datalength, &ind) != CS_SUCCEED) {
					fprintf(stderr, "ct_bind() failed\n");
					delete[] pCol.dszValue;
					return false;
				}
				
				m_dColInfo.push_back(pCol);
				fprintf(stdout, "ctlib_execsql: setting pszColName:%s, pszColValue:%s \n",
					m_dColInfo[iCol].szColName, m_dColInfo[iCol].dszValue);
			}
		break;
		case CS_COMPUTE_RESULT:
			fprintf(stderr, "ctlib_execsql: ct_results(%i,%i):CS_COMPUTE_RESULT\n", results_ret, result_type);
			resultFound = true;
			
			printf("testing compute_result\n");
			if (ct_compute_info (m_pCtCommand, CS_COMP_ID, CS_UNUSED, &compute_id, CS_UNUSED, NULL) != CS_SUCCEED) {
				fprintf(stderr, "ct_compute_info() failed");
				return false;
			}
			if (ct_res_info (m_pCtCommand, CS_NUMDATA, &num_cols, CS_UNUSED, NULL) != CS_SUCCEED) {
				fprintf(stderr, "ct_res_info() failed");
				return false;
			}
			
			m_iNumColumns = num_cols;
			if (num_cols != 1) {
				fprintf(stderr, "compute_id %d num_cols %d != 1", compute_id, num_cols);
				return false;
			}

			CS_DATAFMT datafmt;
			if (ct_describe (m_pCtCommand, 1, &datafmt) != CS_SUCCEED) {
				fprintf(stderr, "ct_describe() failed");
				return 1;
			}
			
			COLINFO pCol;
			pCol.iDataType   = datafmt.datatype;
			pCol.iMaxDataLen = 8000;
			pCol.indp        = 0;
			
			CS_INT datalength;
			datafmt.datatype  = CS_CHAR_TYPE;
			datafmt.format    = CS_FMT_NULLTERM;
			datafmt.maxlength = 8000;
			datafmt.count     = 1;
			datafmt.locale    = NULL;
			
			strncpy (pCol.szColName, (datafmt.namelen) ? datafmt.name : "", 100);
			pCol.dszValue  = new char[datafmt.maxlength + 1];
			
			if (ct_bind (m_pCtCommand, 1, &datafmt, pCol.dszValue, &datalength, &ind) != CS_SUCCEED) {
				fprintf(stderr, "ct_bind() failed\n");
				delete[] pCol.dszValue;
				return false;
			}
			
			m_dColInfo.push_back(pCol);
			fprintf(stdout, "ctlib_execsql: setting pszColName:%s, pszColValue:%s \n",
				m_dColInfo[0].szColName, m_dColInfo[0].dszValue);
			
			break;
		default:
			fprintf(stderr, "ct_results() unexpected return.\n");
			return false;
			break;
		}
		if(resultFound)
			break;
	}
	
	CS_INT num_rows;
	if (ct_res_info (m_pCtCommand, CS_ROW_COUNT, &num_rows, CS_UNUSED, NULL) == CS_SUCCEED)
	{
		if ((long)num_rows != -1) {
			m_iNumRowsAffected = (int) num_rows;
		}
		fprintf(stderr, "m_iNumRowsAffected = %i\n", m_iNumRowsAffected);
	}

	return true;
	
}//ctlib_execsql

CS_RETCODE ctlib_login()
{
	strcpy(USER,     "removed");
	strcpy(PASSWORD, "removed");
	strcpy(SERVER,   "removed");
	strcpy(DATABASE, "removed");
	
	CS_RETCODE ret;
	char query[30];
	TDSCONTEXT *tds_ctx;
	//TDSSOCKET *tds = m_pCtConnection->tds_socket;
	//tds->env.block_size = 512 * 16;

	if ((ret = cs_ctx_alloc(CS_VERSION_100, &m_pCtContext)) != CS_SUCCEED) {
		fprintf(stderr, "Context Alloc failed!\n");
		return ret;
	}

	/* Force default date format, some tests rely on it */
	tds_ctx = (TDSCONTEXT *) (m_pCtContext)->tds_ctx;
	if (tds_ctx && tds_ctx->locale && tds_ctx->locale->date_fmt) {
		free(tds_ctx->locale->date_fmt);
		tds_ctx->locale->date_fmt = strdup("%b %d %Y %I:%M%p");
	}

	if ((ret = ct_init(m_pCtContext, CS_VERSION_100)) != CS_SUCCEED) {
		fprintf(stderr, "Library Init failed!\n");
		return ret;
	}
	if ((ret = ct_callback(m_pCtContext, NULL, CS_SET, CS_CLIENTMSG_CB, 
			       (CS_VOID*) clientmsg_cb)) != CS_SUCCEED) {
		fprintf(stderr, "ct_callback() failed\n");
		return ret;
	}
	if ((ret = ct_callback(m_pCtContext, NULL, CS_SET, CS_SERVERMSG_CB, (CS_VOID*)servermsg_cb)) != CS_SUCCEED) {
		fprintf(stderr, "ct_callback() failed\n");
		return ret;
	}
	
	if ((ret = ct_con_alloc(m_pCtContext, &m_pCtConnection)) != CS_SUCCEED) {
		fprintf(stderr, "Connect Alloc failed!\n");
		return ret;
	}
	if ((ret = ct_con_props(m_pCtConnection, CS_SET, CS_USERNAME, USER, CS_NULLTERM, NULL)) != CS_SUCCEED) {
		fprintf(stderr, "ct_con_props() SET USERNAME failed!\n");
		return ret;
	}
	
	if ((ret = ct_con_props(m_pCtConnection, CS_SET, CS_PASSWORD, PASSWORD, CS_NULLTERM, NULL)) != CS_SUCCEED) {
		fprintf(stderr, "ct_con_props() SET PASSWORD failed!\n");
		return ret;
	}
	
	printf("connecting as %s to %s.%s\n", USER, SERVER, DATABASE);
	
	if ((ret = ct_connect(m_pCtConnection, SERVER, CS_NULLTERM)) != CS_SUCCEED) {
		fprintf(stderr, "Connection failed!\n");
		return ret;
	}
	
	if ((ret = ct_cmd_alloc(m_pCtConnection, &m_pCtCommand)) != CS_SUCCEED) {
		fprintf(stderr, "Command Alloc failed!\n");
		return ret;
	}

	strcpy(query, "use ");
	strncat(query, DATABASE, 20);

	ret = ctlib_execsql(query);
	if (ret != CS_SUCCEED)
		return ret;

	return CS_SUCCEED;
}

CS_RETCODE ctlib_logout()
{
	CS_RETCODE ret;

	fprintf(stdout, "ctlib_logout(): ct_cancel()\n");
	if ((ret = ct_cancel(m_pCtConnection, NULL, CS_CANCEL_ALL)) != CS_SUCCEED) {
		fprintf(stderr, "ct_cancel() failed!\n");
		return ret;
	}
	ct_cmd_drop(m_pCtCommand);
	ct_close(m_pCtConnection, CS_UNUSED);
	ct_con_drop(m_pCtConnection);
	ct_exit(m_pCtContext, CS_UNUSED);
	cs_ctx_drop(m_pCtContext);

	return CS_SUCCEED;
}
// Testing: Retrieve compute results
int main(int argc, char *argv[])
{
	fprintf(stdout, "Trying login\n");
	ctlib_login();
	
	ctlib_execsql ("drop table FAST_TABLE \n");
	ctlib_execsql ("drop table SLOW_TABLE \n");
	
	fprintf (stdout, "create table\n");
	ctlib_execsql (""
			"create table FAST_TABLE (\n"
			"    ID bigint,\n"
			"    BIGSTRING1 varchar(max),\n"
			"    BIGSTRING2 varchar(max),\n"
			"    BIGSTRING3 varchar(max),\n"
			"    BIGSTRING4 varchar(max),\n"
			"    BIGSTRING5 varchar(max),\n"
			"    BIGSTRING6 varchar(max),\n"
			"    BIGSTRING7 varchar(max),\n"
			"    BIGSTRING8 varchar(max),\n"
			"    BIGSTRING9 varchar(max)\n"
			") \n");
			
	ctlib_execsql (""
			"create table SLOW_TABLE (\n"
			"    ID bigint,\n"
			"    BIGSTRING1 nvarchar(max),\n"
			"    BIGSTRING2 nvarchar(max),\n"
			"    BIGSTRING3 nvarchar(max),\n"
			"    BIGSTRING4 nvarchar(max),\n"
			"    BIGSTRING5 nvarchar(max),\n"
			"    BIGSTRING6 nvarchar(max),\n"
			"    BIGSTRING7 nvarchar(max),\n"
			"    BIGSTRING8 nvarchar(max),\n"
			"    BIGSTRING9 nvarchar(max)\n"
			") \n");
	
	fprintf (stdout, "fill table\n");
	ctlib_execsql ("declare @hugestring nvarchar(max); set @hugestring = 'tydahgdsajhgfdhgsafdjhgshfgshadgfjhsagdkjfhgsakjdhfgkjhsagdfkjhgsdjhfgkjsahdgfkjhasgdkjfhgaskjdhfgkjsahdgfkjhsagdkjfhgsakjdhfgjhsadfkjhsgdkjfgskjdhfgjsahgfkjsahdfgkjafsgtydahgdsajhgfdhgsafdjhgshfgshadgfjhsagdkjfhgsakjdhfgkjhsagdfkjhgsdjhfgkjsahdgfkjhasgdkjfhgaskjdhfgkjsahdgfkjhsagdkjfhgsaksahdfgkjafsg'; \n"
			"insert SLOW_TABLE (ID, BIGSTRING1, BIGSTRING2, BIGSTRING3, BIGSTRING4, BIGSTRING5, BIGSTRING6, BIGSTRING7) \n"
			"	select n, @hugestring, @hugestring, @hugestring, @hugestring, @hugestring, @hugestring, @hugestring\n"
			"	from ( \n"
			"		SELECT TOP (30000) n = ROW_NUMBER() OVER (ORDER BY s1.[object_id]) \n"
    		"		FROM sys.all_objects AS s1 \n"
    		"		CROSS JOIN sys.all_objects AS s2 \n"
    		"		ORDER BY s1.[object_id]\n \n"
			"	) AS x; \n");
	
	fprintf (stdout, "expect this not to cause a slowdown on the next ct_cancel\n");
	ctlib_execsql (""
			"select * \n"
			"from SLOW_TABLE \n"
			"");
	
	fprintf (stdout, "expect this not to cause a slowdown on the next ct_cancel\n");
	ctlib_execsql (""
			"select BIGSTRING1 \n"
			"  , BIGSTRING2 \n"
			"  , BIGSTRING3 \n"
			"  , BIGSTRING4 \n"
			"  , BIGSTRING5 \n"
			"  , BIGSTRING6 \n"
			"  , BIGSTRING7 \n"
			"from FAST_TABLE \n"
			"order by  BIGSTRING1 asc, BIGSTRING2 desc , BIGSTRING3 desc , BIGSTRING4 desc, BIGSTRING5 desc, BIGSTRING6 asc, BIGSTRING7 desc \n"
			"");
	
	fprintf (stdout, "expect this to cause a slowdown on the next ct_cancel\n");
	ctlib_execsql (""
			"select BIGSTRING1 \n"
			"  , BIGSTRING2 \n"
			"  , BIGSTRING3 \n"
			"  , BIGSTRING4 \n"
			"  , BIGSTRING5 \n"
			"  , BIGSTRING6 \n"
			"  , BIGSTRING7 \n"
			"from SLOW_TABLE \n"
			"order by  BIGSTRING1 asc, BIGSTRING2 desc , BIGSTRING3 desc , BIGSTRING4 desc, BIGSTRING5 desc, BIGSTRING6 asc, BIGSTRING7 desc \n"
			"");
	
	fprintf (stdout, "droping table: expect slowdown at ct_cancel\n");
	ctlib_execsql ("drop table FAST_TABLE \n");
	ctlib_execsql ("drop table SLOW_TABLE \n");
	
	fprintf(stdout, "Trying logout \n");
	ctlib_logout();

	return 0;
}