April 8, 2013 at 8:55 am
Hi
We've got a production environment with SQL Server 2008 R2 using VB .NET code and .NET Framework 3.5., our database was a SQL Server 2000 migrated to SQL SERVER 2008 R2
We've got this environment running just fine for many time (years) with no drastic changes after migration.
I'l' try to focus this post as an SQL Server 2008 R2 issue as I already post this case in Microsoft ADO NET Forum (without a usuable response or tip to solve it...or reproduce it), if forum admin don't mind all detail is here:
A transaction started with ADO .NET code (sqlConnection, sqlTransaction, sqlCommand involved) COMMITS itself, data is persisted even though .NET Rollback() is executed (also this Rollback() doesn't throw a .NET exception).
no errors have been found in SQL Server logs, we did turn on deadlock events to be written to log but no deadlock events where found
through our code (.NET) we open a connection (sqlConnection instance), begin a transaction ( initialize an sqlTransaction instance through "conn.BeginTransaction" where was already open "conn.Open()" ) and use this sqlTransaction instance and its Connection property to execute 5 SPs
the rare case happens ocassionally when executing the first Stored Procedure through an sqlCommand.ExecuteScalar(), this SP returns an IDENTITY value, internally uses a T-SQL transaction: BEGIN TRAN ... COMMIT with IF @@ERROR<>0 ...ROLLBACK TRAN - RAISERROR- RETURN clauses...
the Identity value first SP returns (not with RETURN clause, with SELECT) we use it as an "ID" parameter for the other 4 SPs
when this rare event happens we know first SP has been executed because: we got the Identity value in our "custom logs", no .NET exceptions neither SQL errors occur, can see persisted data with the returned Identity value in two tables
the Connection property of sqlTransaction instance its turned to nothing (tran.Connection=Nothing) so the next attempt to using it causes a .NET "System.InvalidOperationException...Connection property has not been initialized"...this is how we noticed we got a problem, but we haven´t found why it was lost...
the "rare" of this case is that ~99.97% of the time its working as expected: of the 5 diferent SPs, 2 of them are over other Database (SQL Server 2008 R2 either) in same server, but when this rare case happens this sps are not executed.
we CAN "reprocess" the SAME input, in the same environment, with the same code involved and IT WORKS....
I did try some test doing our first SP to return high severity errors but in developer environment this high severity errors DID cause events in SQL server log, also ADO .NET throws .NET Exceptions
Our .NET code has try... catch blocks and logs any .NET Exception, even I just add a "custom logger" class when this event happens and give us all detail
last thing we try was running "SELECT @@TRANCOUNT" and "SELECT @@SSPID", but as we already know we will lost the Connection I make a "copy" of the Connection poperty of sqlTransaction before invoking the .ExecuteScalar() when this event happens and found that the copy REMAINS (not "Nothing") and also its State = Open
so running "SELECT @@TRANCOUNT" and "SELECT @@SPID" give this results:
@@TRANCOUNT = 1 with sqlTransaction.Connection BEFORE .ExecuteScalar()
@@TRANCOUNT = 1 with "copy" BEFORE .ExecuteScalar()
@@SPID = 97 with sqlTransaction.Connection BEFORE .ExecuteScalar()
@@SPID = 97 with "copy" BEFORE .ExecuteScalar()
.ExecuteScalar() -- case happens, sqlTransaction.Connection = Nothing, also "copy" <> Nothing and "copy.State" = Open
cannot run SELECT @@TRANCOUNT with sqlTransaction.Connection AFTER .ExecuteScalar()
@@TRANCOUNT = 0 (ZERO) with "copy" AFTER .ExecuteScalar()
cannot run SELECT @@SPID with sqlTransaction.Connection AFTER .ExecuteScalar()
@@SPID = 97 with "copy" AFTER .ExecuteScalar()
Unfortunatelly cannot start a sql profiler: 1. its production, 2. doesn´t happen again when re-trying (reprocessing)
Does anyone could give us a clue or tip to find a proper way to reproduce it... or solve it?
thanks a lot
Nemachtiani
April 8, 2013 at 9:46 am
Hi,
It is really difficult from the description of the problem to give any good advice.
I looked at your MSDN forum post and found that to be just as vague.
Can you provide code samples for both the .NET application and the SQL stored procs that shows exactly how you create, intialise and use the SQL Connection, transaction and commands.
At the moment, I cannot see how you are doing these and so cannot possibly know what is happening.
I did, however, spot one thing that looked odd on your MSDN posts - you are passing the SQLTransaction BYVAL to the routine:
Public Function DoInitialInsert(byval CustomerID as string, byval Input as String, [highlight="#ffff11"]byval[/highlight] tran as SqlTransaction) as Int64
This strikes me as wrong - it should be ByRef - and may be part of the issue, but as I said, without a clear view of your code, I am guessing.
MM
select geometry::STGeomFromWKB(0x0106000000020000000103000000010000000B0000001000000000000840000000000000003DD8CCCCCCCCCC0840000000000000003DD8CCCCCCCCCC08408014AE47E17AFC3F040000000000104000CDCCCCCCCCEC3F9C999999999913408014AE47E17AFC3F9C99999999991340000000000000003D0000000000001440000000000000003D000000000000144000000000000000400400000000001040000000000000F03F100000000000084000000000000000401000000000000840000000000000003D0103000000010000000B000000000000000000143D000000000000003D009E99999999B93F000000000000003D009E99999999B93F8014AE47E17AFC3F400000000000F03F00CDCCCCCCCCEC3FA06666666666FE3F8014AE47E17AFC3FA06666666666FE3F000000000000003D1800000000000040000000000000003D18000000000000400000000000000040400000000000F03F000000000000F03F000000000000143D0000000000000040000000000000143D000000000000003D, 0);April 8, 2013 at 10:02 am
Hi Mr. Magoo
Sorry for being "vague" but cannot just post all code for obvious reasons...
I'll check with detail your tip about "byref"...just don't know why the "byval" have been working for years and millions of times executing without this "extra-ordinare" case...
but at this time I could expect anything...
thanks a lot!
Nemachtiani
April 8, 2013 at 10:05 am
Nemachtiani (4/8/2013)
Hi Mr. MagooSorry for being "vague" but cannot just post all code for obvious reasons...
I'll check with detail your tip about "byref"...just don't know why the "byval" have been working for years and millions of times executing without this "extra-ordinare" case...
but at this time I could expect anything...
thanks a lot!
understood about posting the actual code, but even a simple example that show the method you use to create/open/pass the connection around and the same for the transaction object would help.
Also, we can't see what is happening inside your SQL procedures - as you have already said they have code to handle transactions as well, and in my experience this will almost certainly cause problems unless you are extremely careful.
MM
select geometry::STGeomFromWKB(0x0106000000020000000103000000010000000B0000001000000000000840000000000000003DD8CCCCCCCCCC0840000000000000003DD8CCCCCCCCCC08408014AE47E17AFC3F040000000000104000CDCCCCCCCCEC3F9C999999999913408014AE47E17AFC3F9C99999999991340000000000000003D0000000000001440000000000000003D000000000000144000000000000000400400000000001040000000000000F03F100000000000084000000000000000401000000000000840000000000000003D0103000000010000000B000000000000000000143D000000000000003D009E99999999B93F000000000000003D009E99999999B93F8014AE47E17AFC3F400000000000F03F00CDCCCCCCCCEC3FA06666666666FE3F8014AE47E17AFC3FA06666666666FE3F000000000000003D1800000000000040000000000000003D18000000000000400000000000000040400000000000F03F000000000000F03F000000000000143D0000000000000040000000000000143D000000000000003D, 0);April 8, 2013 at 11:06 am
Hi Mr. Magoo
SP content basically is like this:
CREATE PROC [dbo].[spInitialInsert]
@CustomerId varchar(10),
@Input varchar(100)
AS
BEGIN
DECLARE @IdGenerated bigint
SET NOCOUNT ON
BEGIN TRAN
INSERT mytable(CustomerId, Input)
VALUES(@CustomerId, @Input)
IF @@ERROR<>0
BEGIN
ROLLBACK TRAN
RAISERROR 2000100 'custom message error regarding main table'
RETURN -2
END
SELECT @IdGenerated = SCOPE_IDENTITY()
INSERT mytableLog (IdGenerated, LogDate)
VALUES(@IdGenerated, GETDATE())
IF @@ERROR<>0
BEGIN
ROLLBACK TRAN
RAISERROR 2000100 'custom message error regarding log table'
RETURN -2
END
SELECT @IdGenerated
COMMIT TRAN
END
go
-- tables for above code:
go
CREATE TABLE mytable(
IdGenerated bigint not null IDENTITY(1,1),
CustomerId varchar(10) not null,
Input varchar(100) not null
)
go
CREATE TABLE mytableLog(
IdGenerated bigint not null,
LogDate datetime not null
)
go
.NET code for connection and exception management is like this
Public Sub Process(ByVal CustomerId As String, ByVal Input As String)
Dim cn As SqlClient.SqlConnection
Dim tran As SqlClient.SqlTransaction
cn = New SqlClient.SqlConnection(ConnectionString)
cn.Open()
tran = cn.BeginTransaction()
Dim InsertId As Int64
Try
'ocassionally throws invalidoperationexception connection property has not been initialized
InsertId = DoInitialInsert(CustomerId, Input, tran)
'irrelevant code segment that doesn't execute when rare case happens
tran.Commit()'never executes when rare case happens
Catch ex As System.Exception
Try
'when rare case ocurrs this line DONT THROW any further exception
tran.Rollback()
Catch exc As System.Exception
ExceptionManager.Publish(exc)'never happens when rare case ocurr
End Try
Finally
'when rare case ocurrs this line DONT THROW any further exception
cn.Close()
End Try
End Sub
I'm really sorry if i'm beeing vague again, what I try to share its the freaky case and focused of what we've found with SELECT @@TRANCOUNT and SELECT @@SSPID and the state of involved instance of sqlTransaction
If this case were happening all the time it obviously should be a programming issue and could be at .NET code or T-SQL code...
even if this were happening always with the same input it would point to something in the data that makes some code segment with a validation or business rule or anything doing something really rare to make this happen
I did try many scnearios (in my development environment) like committing the sqlTransaction instance at debugging (this not cause de Connection property to point to nothing) or raising high severity errors, or stop sql server, or kill the process...
I just remember i have not trying commiting through a trigger neither check if there is a trigger involved in production... but this trigger should point to a "data input" issue
again, thanks a lot for your time and comments
Nemachtiani
April 8, 2013 at 11:41 am
Hi Nemachtiani,
Thanks, that is much more helpful 🙂
I suspect that something is causing the transaction to rollback in the SQL SP, which is causing a problem with the .NET transaction handler.
I can't say why or how, because I am not debugging the code, but that is my suspicion.(It is a known effect that a rollback in the SQL code can cause the .net transaction to lose it's connection)
I suggest that you do not try to handle rolling back the transaction within the SP as long as you are using the .net SQLTransaction.
Add some logging to your exception handler (you may already have it there, but left out for brevity) to record the contents of the errors collection from the SQLConnection object:
Here:
Catch ex As System.Exception
' Add some error logging from cn.Errors
Try
'when rare case ocurrs this line DONT THROW any further exception
tran.Rollback()
Catch exc As System.Exception
ExceptionManager.Publish(exc)'never happens when rare case ocurr
End Try
Finally
That extra logging should help to identify the issue, but if it is the rollback inside the SP, you will probably just see an invalid connection error or something like that indicating that the transaction has lost it's connection.
Oh, and do change that ByVal to a ByRef, won't you?
Good luck ! 🙂
MM
select geometry::STGeomFromWKB(0x0106000000020000000103000000010000000B0000001000000000000840000000000000003DD8CCCCCCCCCC0840000000000000003DD8CCCCCCCCCC08408014AE47E17AFC3F040000000000104000CDCCCCCCCCEC3F9C999999999913408014AE47E17AFC3F9C99999999991340000000000000003D0000000000001440000000000000003D000000000000144000000000000000400400000000001040000000000000F03F100000000000084000000000000000401000000000000840000000000000003D0103000000010000000B000000000000000000143D000000000000003D009E99999999B93F000000000000003D009E99999999B93F8014AE47E17AFC3F400000000000F03F00CDCCCCCCCCEC3FA06666666666FE3F8014AE47E17AFC3FA06666666666FE3F000000000000003D1800000000000040000000000000003D18000000000000400000000000000040400000000000F03F000000000000F03F000000000000143D0000000000000040000000000000143D000000000000003D, 0);April 8, 2013 at 11:56 am
Hi Mr. Magoo
I'll try first search and log the error collections in my copy of sqlConnection before the ExecuteScalar and even int the first instance of sqlConnection and sqlTransaction
After that I'll give it a try changing the byval of sqlTransaction... (one step at the time)
thanks!
Nemachtiani
April 19, 2013 at 11:43 am
Mmm there's no Error Collection in ADO NET sqlConnection class
A "Error Collection" exists but when sqlExceptions happens
In this case no exceptions occurs before the "loss" of the sqlConnection
how could we make SQL Server to log entire execution of an SPID? is it possible?...
SPID is the only thing i have from SQL Server
there aren't log events regarding our SPID.... :crazy:
Nemachtiani
Viewing 8 posts - 1 through 7 (of 7 total)
You must be logged in to reply to this topic. Login to reply