I have been stuck all day on this issue and cannot seem to find anything online pointing me to what might be causing it.
I have the below logging method in a Logger class and the below code calling the logger. When no exception occurs all the log statements work perfectly, however when an exception occurs the log statements do not run at all (however they do run from the web service call).
Logger Log Method:
public static Guid WriteToSLXLog(string ascendId, string masterDataId, string masterDataType, int? status,
string request, string requestRecieved, Exception ex, bool isError)
{
var connection = ConfigurationManager.ConnectionStrings["AscendConnectionString"];
string connectionString = "context connection=true";
// define INSERT query with parameters
var query =
"INSERT INTO " + AscendTable.SmartLogixLogDataTableName +
" (LogID, LogDate, AscendId, MasterDataId, MasterDataType, Status, Details, Request, RequestRecieved, StackTrace, IsError) " +
"VALUES (@LogID, @LogDate, @AscendId, @MasterDataId, @MasterDataType, @Status, @Details, @Request, @RequestRecieved, @StackTrace, @IsError)";
var logId = Guid.NewGuid();
using (var cn = new SqlConnection(connectionString))
{
if (!cn.State.Equals(ConnectionState.Open))
{
cn.Open();
}
// create command
using (var cmd = new SqlCommand(query, cn))
{
try
{
// define parameters and their values
cmd.Parameters.Add("@LogID", SqlDbType.UniqueIdentifier).Value = logId;
cmd.Parameters.Add("@LogDate", SqlDbType.DateTime).Value = DateTime.Now;
if (ascendId != null)
{
cmd.Parameters.Add("@AscendId", SqlDbType.VarChar, 24).Value = ascendId;
}
else
{
cmd.Parameters.Add("@AscendId", SqlDbType.VarChar, 24).Value = DBNull.Value;
}
cmd.Parameters.Add("@MasterDataId", SqlDbType.VarChar, 50).Value = masterDataId;
cmd.Parameters.Add("@MasterDataType", SqlDbType.VarChar, 50).Value = masterDataType;
if (ex == null)
{
cmd.Parameters.Add("@Status", SqlDbType.VarChar, 50).Value = status.ToString();
}
else
{
cmd.Parameters.Add("@Status", SqlDbType.VarChar, 50).Value = "2";
}
if (ex != null)
{
cmd.Parameters.Add("@Details", SqlDbType.VarChar, -1).Value = ex.Message;
if (ex.StackTrace != null)
{
cmd.Parameters.Add("@StackTrace", SqlDbType.VarChar, -1).Value =
ex.StackTrace;
}
else
{
cmd.Parameters.Add("@StackTrace", SqlDbType.VarChar, -1).Value = DBNull.Value;
}
}
else
{
cmd.Parameters.Add("@Details", SqlDbType.VarChar, -1).Value = "Success";
cmd.Parameters.Add("@StackTrace", SqlDbType.VarChar, -1).Value = DBNull.Value;
}
if (!string.IsNullOrEmpty(request))
{
cmd.Parameters.Add("@Request", SqlDbType.VarChar, -1).Value = request;
}
else
{
cmd.Parameters.Add("@Request", SqlDbType.VarChar, -1).Value = DBNull.Value;
}
if (!string.IsNullOrEmpty(requestRecieved))
{
cmd.Parameters.Add("@RequestRecieved", SqlDbType.VarChar, -1).Value = requestRecieved;
}
else
{
cmd.Parameters.Add("@RequestRecieved", SqlDbType.VarChar, -1).Value = DBNull.Value;
}
if (isError)
{
cmd.Parameters.Add("@IsError", SqlDbType.Bit).Value = 1;
}
else
{
cmd.Parameters.Add("@IsError", SqlDbType.Bit).Value = 0;
}
// open connection, execute INSERT, close connection
cmd.ExecuteNonQuery();
}
catch (Exception e)
{
// Do not want to throw an error if something goes wrong logging
}
}
}
return logId;
}
My Method where the logging issues occur:
public static void CallInsertTruckService(string id, string code, string vinNumber, string licPlateNo)
{
Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "1", "", null, false);
try
{
var truckList = new TruckList();
var truck = new Truck();
truck.TruckId = code;
if (!string.IsNullOrEmpty(vinNumber))
{
truck.VIN = vinNumber;
}
else
{
truck.VIN = "";
}
if (!string.IsNullOrEmpty(licPlateNo))
{
truck.Tag = licPlateNo;
}
else
{
truck.Tag = "";
}
if (!string.IsNullOrEmpty(code))
{
truck.BackOfficeTruckId = code;
}
truckList.Add(truck);
Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "2", "", null, false);
if (truckList.Any())
{
// Call SLX web service
using (var client = new WebClient())
{
var uri = SmartLogixConstants.LocalSmartLogixIntUrl;
uri += "SmartLogixApi/PushTruck";
client.Headers.Clear();
client.Headers.Add("content-type", "application/json");
client.Headers.Add("FirestreamSecretToken", SmartLogixConstants.FirestreamSecretToken);
var serialisedData = JsonConvert.SerializeObject(truckList, new JsonSerializerSettings
{
ReferenceLoopHandling = ReferenceLoopHandling.Serialize
});
// HTTP POST
var response = client.UploadString(uri, serialisedData);
var result = JsonConvert.DeserializeObject<SmartLogixResponse>(response);
Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "3", "", null, false);
if (result == null || result.ResponseStatus != 1)
{
// Something went wrong
throw new ApplicationException("Error in SLX");
}
Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, result.ResponseStatus, serialisedData,
null, null, false);
}
}
}
catch (Exception ex)
{
Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "4", "", null, false);
throw;
}
finally
{
Logger.WriteToSLXLog(id, code, MasterDataType.TruckType, 4, "5", "", null, false);
}
}
As you can see I have added several log statements throughout the method. All of these log statements except the one in the catch block are successful if no exception is thrown. If an exception is thrown then none of them are successful. For most of them the values are exactly the same whether or not there is an exception so I know its not an issue with the values being passed. I am thinking something weird is happening that causes a rollback or something, but I am not using a transaction or anything here. One last thing this DLL is being run through the SQL CLR which is why I am using "context connection=true" for my connection string.
Thanks in advance.
Edit:
I tried adding the following as my connection string but I get an exception when trying to .Open the connection now that says "Transaction context in use by another session". I am thinking this has to do with me calling this SQL CLR procedure through a trigger. The connection string I tried is
connectionString = "Trusted_Connection=true;Data Source=(local)\\AARONSQLSERVER;Initial Catalog=Demo409;Integrated Security=True;";
Also here is the trigger:
CREATE TRIGGER [dbo].[PushToSLXOnVehicleInsert]
ON [dbo].[Vehicle] AFTER INSERT
AS
BEGIN
-- SET NOCOUNT ON added to prevent extra result sets from
-- interfering with SELECT statements.
SET NOCOUNT ON;
DECLARE @returnValue int
DECLARE @newLastModifiedDate datetime = null
DECLARE @currentId bigint = null
DECLARE @counter int = 0;
DECLARE @maxCounter int
DECLARE @currentCode varchar(24) = null
DECLARE @currentVinNumber varchar(24)
DECLARE @currentLicPlateNo varchar(30)
declare @tmp table
(
id int not null
primary key(id)
)
insert @tmp
select VehicleID from INSERTED
SELECT @maxCounter = Count(*) FROM INSERTED GROUP BY VehicleID
BEGIN TRY
WHILE (@counter < @maxCounter)
BEGIN
select top 1 @currentId = id from @tmp
SELECT @currentCode = Code, @currentVinNumber = VINNumber, @currentLicPlateNo = LicPlateNo FROM INSERTED WHERE INSERTED.VehicleID = @currentId
if (@currentId is not null)
BEGIN
EXEC dbo.SLX_CallInsertTruckService
@id = @currentId,
@code = @currentCode,
@vinNumber = @currentVinNumber,
@licPlateNo = @currentLicPlateNo
END
delete from @tmp where id = @currentId
set @counter = @counter + 1;
END
END TRY
BEGIN CATCH
DECLARE @ErrorMessage NVARCHAR(4000);
DECLARE @ErrorSeverity INT;
DECLARE @ErrorState INT;
SELECT
@ErrorMessage = ERROR_MESSAGE(),
@ErrorSeverity = ERROR_SEVERITY(),
@ErrorState = ERROR_STATE();
IF (@ErrorMessage like '%Error in SLX%')
BEGIN
SET @ErrorMessage = 'Error in SLX. Please contact SLX for more information.'
END
RAISERROR (@ErrorMessage, -- Message text.
@ErrorSeverity, -- Severity.
@ErrorState -- State.
);
END CATCH;
END
GO
The main issue here is that the SQLCLR Stored Procedure is being called from within a Trigger. A Trigger always runs within the context of a Transaction (to bind it to the DML operation that initiated the Trigger). A Trigger also implicitly sets XACT_ABORT to ON which cancels the Transaction if any error occurs. This is why none of the logging statements persist when an exception is thrown: the Transaction is auto-rolled-back, taking with it any changes made in the same Session, including the logging statements (because the Context Connection is the same Session), as well as the original DML statement.
You have three fairly simple options, though they leave you with an overall architectural problem, or a not-so-difficult-but-a-little-more-work option that solves the immediate issue as well as the larger architectural problem. First, the three simple options:
You can execute SET XACT_ABORT OFF; at the beginning of the Trigger. This will allow the TRY ... CATCH construct to work as you are expecting it to. HOWEVER, this also shifts the responsibility to you issue a ROLLBACK (usually in the CATCH block), unless you want the original DML statement to succeed no matter what, even if the Web Service calls and logging fail. Of course, if you issue a ROLLBACK, then none of the logging statements will persist, even if the Web Service still registers all of the calls that were successful, if any were.
You can leave SET XACT_ABORT alone and use a regular / external connection to SQL Server. A regular connection will be an entirely separate Connection and Session, hence it can operate independantly with regards to the Transaction. Unlike the SET XACT_ABORT OFF; option, this would allow the Trigger to operate "normally" (i.e. any error would roll-back any changes made natively in the Trigger as well as the original DML statement) while still allowing the logging INSERT statements to persist (since they were made outside of the local Transaction).
You are already calling a Web Service so the Assembly already has the necessary permissions to do this without making any additional changes. You just need to use a proper connection string (there are a few errors in your syntax), probably something along the lines of:
connectionString = @"Trusted_Connection=True; Server=(local)\AARONSQLSERVER; Database=Demo409; Enlist=False;";
The "Enlist=False;" part (scroll to the far right) is very important: without it you will continue to get the "Transaction context in use by another session" error.
If you want to stick with the Context Connection (it is a little faster) and allow for any errors outside of the Web Service to roll-back the original DML statement and all logging statements, while ignoring errors from the Web Service, or even from the logging INSERT statements, then you can simply not re-throw the exception in the catch block of CallInsertTruckService. You could instead set a variable to indicate a return code. Since this is a Stored Procedure, it can return SqlInt32 instead of void. Then you can get that value by declaring an INT variable and including it in the EXEC call as follows:
EXEC @ReturnCode = dbo.SLX_CallInsertTruckService ...;
Just declare a variable at the top of CallInsertTruckService and initialize it to 0. Then set it to some other value in the catch block. And at the end of the method, include a return _ReturnCode;.
That being said, no matter which of those choices you pick, you are still left with two fairly large problems:
The DML statement and its system-initiated Transaction are impeded by the Web Service calls. The Transaction will be left open for much longer than it should be, and this could at the very least increase blocking related to the Vehicle Table. While I am certainly an advocate of doing Web Service calls via SQLCLR, I would strongly recommend against doing so within a Trigger.
If each VehicleID that is inserted should be passed over to the Web Service, then if there is an error in one Web Service call, the remaining VehicleIDs will be skipped, and even if they aren't (option # 3 above would continue processing the rows in @tmp) then at the very least the one that just had the error won't ever be retried later.
Hence the ideal approach, which solves these two rather important issues as well the initial logging issue, is to move to a disconnected asynchronous model. You can set up a queue table to hold the Vehile info to process based on each INSERT. The Trigger would do a simple:
INSERT INTO dbo.PushToSLXQueue (VehicleID, Code, VINNumber, LicPlateNo)
SELECT VehicleID, Code, VINNumber, LicPlateNo
FROM INSERTED;
Then create a Stored Procedure that reads an item from the queue table, calls the Web Service, and if successful, then deletes that entry from the queue table. Schedule this Stored Procedure from a SQL Server Agent job to run every 10 minutes or something like that.
If there are records that will never process, then you can add a RetryCount column to the queue table, default it to 0, and upon the Web Service getting an error, increment RetryCount instead of removing the row. Then you can update the "get entry to process" SELECT query to include WHERE RetryCount < 5 or whatever limit you want to set.
There are a few issues here, with various levels of impact:
Why is id a BIGINT in the T-SQL code yet a string in the C# code?
Just FYI, the WHILE (@counter < @maxCounter) loop is inefficient and error prone compared to using an actual CURSOR. I would get rid of the @tmp Table Variable and @maxCounter.
At the very least change SELECT @maxCounter = Count(*) FROM INSERTED GROUP BY VehicleID to be just SET @maxCounter = @@ROWCOUNT; ;-). But swapping out for a real CURSOR would be best.
If the CallInsertTruckService(string id, string code, string vinNumber, string licPlateNo) signature is the actual method decorated with [SqlProcedure()], then you really should be using SqlString instead of string. Get the native string value from each parameter using the .Value property of the SqlString parameter. You can then set the proper size using the [SqlFacet()] attribute as follows:
[SqlFacet(MaxSize=24)] SqlString vinNumber
For more info on working with SQLCLR in general, please see the series that I am writing on this topic over at SQL Server Central: Stairway to SQLCLR (free registration is required to read content on that site).