Skip to Content.
Sympa Menu

freetds - Re: [freetds] New BUG: update/delete returns -1 instead of correct affected rows on Merge Publication on MSSQL 2000 SP3a

freetds AT lists.ibiblio.org

Subject: FreeTDS Development Group

List archive

Chronological Thread  
  • From: Stefano Coletta <s.coletta AT uni.it>
  • To: FreeTDS Development Group <freetds AT lists.ibiblio.org>
  • Subject: Re: [freetds] New BUG: update/delete returns -1 instead of correct affected rows on Merge Publication on MSSQL 2000 SP3a
  • Date: Fri, 09 Jan 2004 00:56:38 +0100

Lowden, James K wrote:

I'm almost sure to have found a bug in the freetds lib (even 0.62rc3) that occurs only when I try to do an update or delete against Microsoft SQL Server 2000 SP3a while the database is in Merge Replication. The problem arises when I try to read the "rows affected" property which returns always -1 instead of the correct number of affected rows.
...
I've tested the Rows Affected property in Microsoft Access Visual Basic with an ADP project and it behaves correctly returning proper values.


(Do you mean ADO?)

No, I mean ADP: Access Data Project, a special M$ Access file that permits you to connect easily with SQL Server.

This is the VB code I used to make the test:

Public Function Test()

Dim m_oRecordset As ADODB.Recordset

Dim oConnection1 As ADODB.Connection
Dim affected As Long
Set oConnection1 = New ADODB.Connection

' m_sConnStr = "Provider='SQLOLEDB';Data Source='DBNAME-NOREPLICA';" & _
' "Initial Catalog='test'; " & _
' "User ID='sa';Password='******';"

m_sConnStr = "Provider='SQLOLEDB';Data Source='DBNAME-WITHREPLICA';" & _
"Initial Catalog='test'; " & _
"User ID='sa';Password='******';"

oConnection1.Open (m_sConnStr)


Set m_oRecordset = New ADODB.Recordset

'sSQL = "update radonline set v_username='test' where v_username='oldtest'"
sSQL = "update radonline set v_username='oldtest' where v_username='test'"

oConnection1.Execute sSQL, affected

'm_oRecordset.Open sSQL, oConnection1, adOpenKeyset

MsgBox "Rows: " & CStr(affected)

' MsgBox "RecordCount: " & CStr(m_oRecordset.RecordCount)
' MsgBox "Conn state: " & GetState(oConnection1.State)

oConnection1.Close

End Function

Public Function GetState(intState As Integer) As String

Select Case intState
Case adStateClosed
GetState = "adStateClosed"
Case adStateOpen
GetState = "adStateOpen"
End Select

End Function

You can play with this for your tests. But believe in me, it returns correct values, it speaks native M$ language. ;)

It seems to behave this way only with MERGE REPLICATION and not with other types of replication.


It may be that the TDS stream is sending us a surprise from the downstream
database. I can't think of any other reason that FreeTDS would react
differently to the two databases. What you're doing is a little unusual; it
could well be that you're the first one to update a replicated database with
FreeTDS. I suppose that's progress....

Oh, maybe :) We use FreeTDS in mission critical services here. We use it mainly to interface our OTRS Trouble Ticketing system (Perl) with SQL Server and our Centralized Radius Authentication cluster (Perl).
However it is very strange that behaviour because from my point of view an application has not to be replica aware. In fact SQL Server is supposed to present the API for connections and transactions exactly the same as it is on one single DB. Isn't it?

If you could, please post a TDSDUMP log of the failed transaction, so we can
analyze the packets. I assume you're using TDS 7.0 or 8.0, for which the
log will not contain the login packet, so you don't have to worry about
exposing username/password information. Please keep the session as brief as
possible.
If the log is too large to post (>75 KB), it's better to make it available
on a website. But if you can't do that, post it anyway, and I'll release
it. It won't be *too* much bigger than that. That can mean a delay of some
hours, however.
Here they are. I've gzipped the files so they are very small.

The files that end with "ok" are the correct updates against a single SQL
Server database.
The others that end with "debug" are the failed updates against a replicated
SQL Server database with merge replication.
IMPORTANT NOTE: I mean 'failed' only for affected rows result! The updates
are being correctly made in the database table!

The logs contains only the minimum data you need to discover the bug. There
is the Radiator inizialization and update query.

To ease your work I've attached even the radiator log to see what it says
about the error.
Note the line that say:

DEBUG: rc is: X

This is not Radiator debug code but a line of code that I've inserted on my
own to show you the rc (rowcount) variable content of the original Radiator
code.

I've attached the freetds.conf also to let you check what parameters I'm
using.

With both correct & odd logs you can simply make an eyes diff :)

However I've noticed that against the replicated DB the results of call ct_fetch() are negative numbers. Maybe this can help.

2004-01-08 19:52:58.994002 inside ct_fetch() process_row_tokens returned -2

Is it normal?

If you can post a log before the weekend, perhaps we can incorporate a
remedy into the upcoming 0.62 release. I'd like to see that. The only
difficulty I foresee is that none of the developers has your particular
setup, so we'd be relying on you to test any potential fix.
I'm glad to help you and even my company because we plan to use FreeTDS for any Linux software that has to deal with M$ Sql Server :)

However to make it easy for you to test the patch I've a suggestion for you:

1) Download VMWare Workstation 4.0.5 Evaluation (It works for 30 days).
2) Install and create a VM with Windows 2000 or 2003 (I use both 2000 and
2003 configurations) and use the Disk on File mode to emulate the Hard Disk
(do not use a real partition, is uncomfortable for our purpose).
3) Install SQL Server and configure it on the newly installed VM Win.
4) Make a copy of your new OS (ie just make a copy of the file) and you have
another perfectly functional operating system with SQL Server.
5) Make changes to the 2nd OS configuration like: IP address, machine name
and so on...
6) Run both VMs at the same time and create the test DB.
7) Configure the MSSQL replica.
Well done you have a perfectly functional test system without using two real
servers :)
NOTE: I don't know if Windows complains about SID, anyway there are a lot of
tools out there to change the SID of WIndows, like Norton Ghost does to make
multiple installations at the same time from a single Windows Image.

However feel free to send me patches and I'll test it for you.

Good luck :)

--
Stefano Coletta

Unidata S.p.a.
Via Portuense, 1555 - 00050 Roma ( Ponte Galeria )
Tel +39 06650951
Fax +39 0665095002
E-mail s.coletta AT uni.it
Italy

http://www.mindcreations.com


#
#
# $Id: freetds.conf,v 1.7 2002/10/17 15:11:02 castellano Exp $
#
# The freetds.conf file is a replacement for the original interfaces
# file developed by Sybase. You may use either this or the interfaces
# file, but not both.
#
# FreeTDS will search for a conf file in the following order:
#
# 1) check if a file was set programatically via dbsetifile() and
# is in .conf format, if so use that,
#
# 2) otherwise, if env variable FREETDSCONF specifies a properly
# formatted config file, use it,
#
# 3) otherwise, look in ~/.freetds.conf,
#
# 4) otherwise, look in @sysconfdir@/freetds.conf
#
# If FreeTDS has found no suitable conf file it will then search for
# an interfaces file in the following order:
#
# 1) check if a file was set programatically via dbsetifile() and
# is in interfaces format, if so use that,
#
# 2) look in ~/.interfaces
#
# 3) look in $SYBASE/interfaces (where $SYBASE is an environment
# variable)
#
# Only hostname, port number, and protocol version can be specified
# using the interfaces format.
#
# The conf file format follows a modified Samba style layout. There
# is a [global] section which will affect all database servers and
# basic program behaviour, and a section headed with the database
# server's name which will have settings which override the global
# ones.
#
# Note that environment variables TDSVER, TDSDUMP, TDSPORT, TDSQUERY,
# and TDSHOST will override values set by a .conf or .interfaces file.
#
# To review the processing of the above, set env variable TDSDUMPCONFIG
# to a file name to log configuration processing.
#
# Global settings, any value here may be overridden by a database
# server specific section
[global]
# TDS protocol version
tds version = 4.2

initial block size = 512

swap broken dates = no

swap broken money = no

# Database server login method, if both server and domain
# logins are enabled, domain login is tried first if a domain
# is specified, and if that fails the server login will be used.
try server login = yes
try domain login = no

# The default authentication domain, can be overridden by
# specifying a username with a domain prefix, e.g. DOMAIN\username
; nt domain = WORKGROUP

# If the server responds with different domain try that one?
cross domain login = no

# Whether to write a TDSDUMP file for diagnostic purposes
# (setting this to /tmp is insecure on a multi-user system)
dump file = /tmp/freetds.log
debug level = 10

# Command and connection timeouts
; timeout = 10
; connect timeout = 10

# If you get out of memory errors, it may mean that your client
# is trying to allocate a huge buffer for a TEXT field.
# (Microsoft servers sometimes pretend TEXT columns are
# 4 GB wide!) If you have this problem, try setting
# 'text size' to a more reasonable limit
text size = 64512

# This is a Sybase hosted database server, if you are directly on the
# net you can use it to test.
[JDBC]
host = 192.138.151.39
port = 4444
tds version = 5.0

# The same server, using TDS 4.2. Used in configuration examples for the
# pool server, since the pool server supports only TDS 4.2.
[JDBC_42]
host = 192.138.151.39
port = 4444
tds version = 4.2

# The client connecting to the pool server will use this to find its
# listening socket. This entry assumes that the client is on the same
# system as the pool server.
[mypool]
host = 127.0.0.1
port = 5000
tds version = 4.2

# A typical Microsoft SQL Server 7.0 configuration
;[MyServer70]
; host = ntmachine.domain.com
; port = 1433
; tds version = 7.0

# A typical Microsoft SQL Server 7.0 configuration using domain logins
;[MyServer70]
; host = ntmachine.domain.com
; port = 1433
; tds version = 7.0
; try domain login = yes
; try server login = no
; nt domain = MYDOMAIN

# A typical Microsoft SQL Server 6.x configuration
;[MyServer65]
; host = ntmachine.domain.com
; port = 1433
; tds version = 4.2


; WORKING DATABASE (SIMPLE)
[sql01]
host = 192.168.96.21
port = 1433
tds version = 7.0


; NOT WORKING DATABASE (MERGE REPLICATION)
[bonnie]
host = 217.72.103.103
port = 1433
tds version = 7.0

Attachment: freetds.log.debug.gz
Description: GNU Zip compressed data

Attachment: freetds.log.ok.gz
Description: GNU Zip compressed data

Thu Jan 8 19:47:59 2004: NOTICE: Server started: Radiator 3.8 on
arlecchino.uni.it
Thu Jan 8 19:49:34 2004: DEBUG: Packet dump:
*** Received from 192.168.97.197 port 3406 ....
Code: Access-Request
Identifier: 6
Authentic: 1073587871
Attributes:
User-Name = "registrazione AT openaccess.it"
User-Password = "<246>{x<236><18>d<191>3<25><4>c<160>OGt<131>"
NAS-IP-Address = 217.72.110.16
NAS-Port = 80
Called-Station-Id = "650519929"
Calling-Station-Id = "78359804"
Service-Type = Framed-User
Framed-Protocol = PPP
NAS-Port-Type = Async

Thu Jan 8 19:49:34 2004: DEBUG: Handling request with Handler 'Realm=DEFAULT'
Thu Jan 8 19:49:34 2004: DEBUG: Rewrote user name to registrazione
Thu Jan 8 19:49:34 2004: DEBUG: Deleting session for
registrazione AT openaccess.it, 217.72.110.16, 80
Thu Jan 8 19:49:34 2004: DEBUG: do query is: 'DELETE FROM RADONLINE where
i_NASPort=80 and v_NASIdentifier='217.72.110.16'':

Thu Jan 8 19:49:34 2004: DEBUG: rc is: 1

Thu Jan 8 19:49:34 2004: DEBUG: Query is: 'SELECT v_NASIdentifier,
i_NASPort, v_acctsessionid from RADONLINE where
v_username='registrazione AT openaccess.it'':

Thu Jan 8 19:49:34 2004: DEBUG: Handling with Radius::AuthGROUP
Thu Jan 8 19:49:34 2004: DEBUG: Handling with Radius::AuthSQL
Thu Jan 8 19:49:34 2004: DEBUG: Handling with Radius::AuthSQL: SQL01-realm
Thu Jan 8 19:49:34 2004: DEBUG: Query is: 'select v_password,
i_session_timeout,v_ip_fisso, v_netmask, v_route_fissa, v_pool_hint,
i_simultaneous_use from SUBSCRIBERS where v_username='registrazione' and
v_realm='openaccess.it'':

Thu Jan 8 19:49:34 2004: DEBUG: Radius::AuthSQL looks for match with
registrazione
Thu Jan 8 19:49:34 2004: DEBUG: Query is: 'select v_password,
i_session_timeout,v_ip_fisso, v_netmask, v_route_fissa, v_pool_hint,
i_simultaneous_use from SUBSCRIBERS where v_username='DEFAULT' and
v_realm='openaccess.it'':

Thu Jan 8 19:49:34 2004: DEBUG: Handling with Radius::AuthGROUP
Thu Jan 8 19:49:34 2004: DEBUG: Handling with Radius::AuthSQL
Thu Jan 8 19:49:34 2004: DEBUG: Handling with Radius::AuthSQL:
SQL-Registrazione
Thu Jan 8 19:49:34 2004: DEBUG: Query is: 'select i_session_timeout,
i_simultaneous_use from RESELLERS where v_username='registrazione' and
v_realm='openaccess.it'':

Thu Jan 8 19:49:34 2004: DEBUG: Radius::AuthSQL looks for match with
registrazione
Thu Jan 8 19:49:34 2004: DEBUG: Query is: 'SELECT v_NASIdentifier,
i_NASPort, v_acctsessionid from RADONLINE where
v_username='registrazione AT openaccess.it'':

Thu Jan 8 19:49:34 2004: DEBUG: Radius::AuthSQL ACCEPT:
Thu Jan 8 19:49:34 2004: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Jan 8 19:49:34 2004: DEBUG: Query is: 'select top 1 TIME_STAMP, YIADDR,
SUBNETMASK, DNSSERVER from RADPOOL where POOL='reserved' and STATE=0 order by
TIME_STAMP':

Thu Jan 8 19:49:34 2004: DEBUG: do query is: 'update RADPOOL set
STATE=1,TIME_STAMP=1073587774,EXPIRY=1073591374, USERNAME='registrazione',
POOL='openaccess.it' where YIADDR='213.233.28.94' and TIME_STAMP =94':

Thu Jan 8 19:49:34 2004: DEBUG: rc is: -1

Thu Jan 8 19:49:34 2004: INFO: Access rejected for registrazione: Too many
simultaneous address requests
Thu Jan 8 19:49:34 2004: DEBUG: Packet dump:
*** Sending to 192.168.97.197 port 3406 ....
Code: Access-Reject
Identifier: 6
Authentic: 1073587871
Attributes:
Session-Timeout = 3600
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-Routing = None
Framed-MTU = 1500
Framed-Compression = Van-Jacobson-TCP-IP
Reply-Message = "Too many simultaneous address requests"


Thu Jan 8 20:05:44 2004: DEBUG: Finished reading configuration file
'/home/radiator/etc/radius.cfg'
Thu Jan 8 20:05:44 2004: DEBUG: Reading dictionary file
'/home/radiator/etc//dictionary'
Thu Jan 8 20:05:45 2004: DEBUG: Creating authentication port 0.0.0.0:1812
Thu Jan 8 20:05:45 2004: DEBUG: Creating accounting port 0.0.0.0:1813
Thu Jan 8 20:05:45 2004: NOTICE: Server started: Radiator 3.8 on
arlecchino.uni.it
Thu Jan 8 20:06:13 2004: DEBUG: Packet dump:
*** Received from 192.168.97.197 port 4122 ....
Code: Access-Request
Identifier: 0
Authentic: 1073588869
Attributes:
User-Name = "registrazione AT openaccess.it"
User-Password = "<198><193>w<13>3 "<147><209><7>Z<201>k<157><195>Y"
NAS-IP-Address = 217.72.110.16
NAS-Port = 80
Called-Station-Id = "650519929"
Calling-Station-Id = "78359804"
Service-Type = Framed-User
Framed-Protocol = PPP
NAS-Port-Type = Async

Thu Jan 8 20:06:13 2004: DEBUG: Handling request with Handler 'Realm=DEFAULT'
Thu Jan 8 20:06:13 2004: DEBUG: Rewrote user name to registrazione
Thu Jan 8 20:06:13 2004: DEBUG: Deleting session for
registrazione AT openaccess.it, 217.72.110.16, 80
Thu Jan 8 20:06:13 2004: DEBUG: do query is: 'DELETE FROM RADONLINE where
i_NASPort=80 and v_NASIdentifier='217.72.110.16'':

Thu Jan 8 20:06:13 2004: DEBUG: rc is: 139795672

Thu Jan 8 20:06:13 2004: DEBUG: Query is: 'SELECT v_NASIdentifier,
i_NASPort, v_acctsessionid from RADONLINE where
v_username='registrazione AT openaccess.it'':

Thu Jan 8 20:06:13 2004: DEBUG: Handling with Radius::AuthGROUP
Thu Jan 8 20:06:13 2004: DEBUG: Handling with Radius::AuthSQL
Thu Jan 8 20:06:13 2004: DEBUG: Handling with Radius::AuthSQL: SQL01-realm
Thu Jan 8 20:06:13 2004: DEBUG: Query is: 'select v_password,
i_session_timeout,v_ip_fisso, v_netmask, v_route_fissa, v_pool_hint,
i_simultaneous_use from SUBSCRIBERS where v_username='registrazione' and
v_realm='openaccess.it'':

Thu Jan 8 20:06:13 2004: DEBUG: Radius::AuthSQL looks for match with
registrazione
Thu Jan 8 20:06:13 2004: DEBUG: Query is: 'select v_password,
i_session_timeout,v_ip_fisso, v_netmask, v_route_fissa, v_pool_hint,
i_simultaneous_use from SUBSCRIBERS where v_username='DEFAULT' and
v_realm='openaccess.it'':

Thu Jan 8 20:06:13 2004: DEBUG: Handling with Radius::AuthGROUP
Thu Jan 8 20:06:13 2004: DEBUG: Handling with Radius::AuthSQL
Thu Jan 8 20:06:13 2004: DEBUG: Handling with Radius::AuthSQL:
SQL-Registrazione
Thu Jan 8 20:06:13 2004: DEBUG: Query is: 'select i_session_timeout,
i_simultaneous_use from RESELLERS where v_username='registrazione' and
v_realm='openaccess.it'':

Thu Jan 8 20:06:13 2004: DEBUG: Radius::AuthSQL looks for match with
registrazione
Thu Jan 8 20:06:13 2004: DEBUG: Query is: 'SELECT v_NASIdentifier,
i_NASPort, v_acctsessionid from RADONLINE where
v_username='registrazione AT openaccess.it'':

Thu Jan 8 20:06:13 2004: DEBUG: Radius::AuthSQL ACCEPT:
Thu Jan 8 20:06:13 2004: DEBUG: Handling with Radius::AuthDYNADDRESS
Thu Jan 8 20:06:13 2004: DEBUG: Query is: 'select top 1 TIME_STAMP, YIADDR,
SUBNETMASK, DNSSERVER from RADPOOL where POOL='reserved' and STATE=0 order by
TIME_STAMP':

Thu Jan 8 20:06:13 2004: DEBUG: do query is: 'update RADPOOL set
STATE=1,TIME_STAMP=1073588773,EXPIRY=1073592373, USERNAME='registrazione',
POOL='openaccess.it' where YIADDR='192.168.0.4' and TIME_STAMP =0':

Thu Jan 8 20:06:13 2004: DEBUG: rc is: 1

Thu Jan 8 20:06:13 2004: DEBUG: Access accepted for registrazione
Thu Jan 8 20:06:13 2004: DEBUG: Packet dump:
*** Sending to 192.168.97.197 port 4122 ....
Code: Access-Accept
Identifier: 0
Authentic: 1073588869
Attributes:
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-Routing = None
Framed-MTU = 1500
Framed-Compression = Van-Jacobson-TCP-IP
Framed-IP-Netmask = 255.255.255.0
Framed-IP-Address = 192.168.0.4





Archive powered by MHonArc 2.6.24.

Top of Page