I'm working on an application, based on another application, and both are based on Telerik OpenAccess for reading an SQL-Server database.
Regularly, my customer is experiencing the following exception:
Telerik.OpenAccess.OpenAccessException: Change operation canceled by user.
at OpenAccessRuntime.ExceptionWrapper.Throw()
at OpenAccessRuntime.DataObjects.PCStateMan.handleException(Exception x)
at OpenAccessRuntime.DataObjects.PCStateMan.SetField[T](PersistenceCapable _pc, Int32 field, T currentValue, T newValue)
at App1.Server.Core.Domain.CommandOrderPart.OpenAccessEnhancedSet_status(CommandOrderPart owner, OrderStatus value)
at App1.Server.Core.Domain.CommandOrderPart.set_Status(OrderStatus value)
at App2.Helpers.ExtensionMethods.SetStatus(CommandOrderPart orderPart, String status) in C:\Source1.cs:line 47
at App2.Manager.RequestOrderStatus(JbtOrder order) in C:\Source2.cs:line 668
Telerik.OpenAccess.OpenAccessException: Change operation canceled by user.
at OpenAccessRuntime.ExceptionWrapper.Throw()
at OpenAccessRuntime.DataObjects.PCStateMan.handleException(Exception x)
at OpenAccessRuntime.DataObjects.PCStateMan.SetField[T](PersistenceCapable _pc, Int32 field, T currentValue, T newValue)
at App1.Server.Core.Domain.CommandOrderPart.OpenAccessEnhancedSet_status(CommandOrderPart owner, OrderStatus value)
at App1.Server.Core.Domain.CommandOrderPart.set_Status(OrderStatus value)
at App2.Helpers.ExtensionMethods.SetStatus(CommandOrderPart orderPart, String status) in C:\Source1.cs:line 47
at App2.Manager.RequestOrderStatus(JbtOrder order) in C:\Source2.cs:line 668
What does this mean exactly "Change operation canceled by user"? Ok, I understand that my applications want to set a status (which is a "change operation"), but who is the user, creating that Exception
? Can I get more information from the database? Which table or view or diagnostic? ...?
After decompiling Telerik OpenAccess DLL, I have found two instances of Change operation canceled by user
:
private ChangeEventArgs FireChanging(
object pc,
int field,
object oldV,
object newV)
{
ChangeEventArgs ev = new ChangeEventArgs(pc, this.cmd.getFieldName(field), oldV, newV, this.state == (short) 4, true);
this.repository.tracker.FireChanging(ev);
return !ev.Cancel ? ev : throw new OpenAccessException("Change operation canceled by user.", true);
}
/// <summary>Raises the Changing event.</summary>
/// <remarks>Not intended for application use.</remarks>
/// <param name="ev">The event to raise.</param>
public void FireChanging(ChangeEventArgs ev)
{
if (this.evChanging == null)
return;
this.evChanging(this.owner, ev);
if (ev.Cancel)
throw new OpenAccessException("Change operation canceled by user.", true);
}
In "PcStateMan.cs", the following can be seen in handleException(...)
:
private void handleException(Exception x)
{
if (BindingSupportImpl.Instance.isOwnException(x))
throw new ExceptionWrapper(x).Throw();
throw BindingSupportImpl.Instance.internally(x.Message, x).Throw();
}
This means that the condition BindingSupportImpl.Instance.isOwnException(x)
is true (whatever that means).
Edit: timeout of application's DB timeout:
In case a timeout is configured, for App1
and/or App2
, this can happen (just imagine that App1.....CommandOrderPart.Set()
takes too long while App2
has a DB timeout setting, this might already cause the issue). Where can I find those timeout settings?
Edit: proposal to find the SQL-statement, causing this situation
Apparently, the problem occurs when the status of a App1.....CommandOrderPart
is changed. An SQL-trace can be created, monitoring all transactions, performed on that object, as follows:
DECLARE @TraceID INT;
DECLARE @MaxFileSize BIGINT = 50; -- File size limit in MB
DECLARE @TraceFilePath NVARCHAR(256) = N'C:\SQLTraces\Trace_OrderPart'; -- Base trace file path
-- Step 1: Create a new trace
EXEC sp_trace_create
@traceid = @TraceID OUTPUT,
@options = 2, -- File rollover enabled
@tracefile = @TraceFilePath,
@maxfilesize = @MaxFileSize,
@stoptime = NULL; -- No automatic stop
-- Step 2: Set events to capture
-- Add events to monitor SQL statements and related information
EXEC sp_trace_setevent @TraceID, 16, 1, 1; -- EventClass (SP:Attention) TextData
EXEC sp_trace_setevent @TraceID, 16, 4, 1; -- EventClass (SP:Attention) TransactionId
EXEC sp_trace_setevent @TraceID, 16, 9, 1; -- EventClass (SP:Attention) ClientProcessID
EXEC sp_trace_setevent @TraceID, 16, 10, 1; -- EventClass (SP:Attention) ApplicationName
EXEC sp_trace_setevent @TraceID, 16, 11, 1; -- EventClass (SP:Attention) LoginName
EXEC sp_trace_setevent @TraceID, 16, 12, 1; -- EventClass (SP:Attention) SPID
EXEC sp_trace_setevent @TraceID, 16, 13, 1; -- EventClass (SP:Attention) ClientProcessID
EXEC sp_trace_setevent @TraceID, 16, 14, 1; -- EventClass (SP:Attention) StartTime
EXEC sp_trace_setevent @TraceID, 16, 15, 1; -- EventClass (SP:Attention) EndTime
EXEC sp_trace_setevent @TraceID, 16, 20, 1; -- EventClass (SP:Attention) Severity
EXEC sp_trace_setevent @TraceID, 16, 23, 1; -- EventClass (SP:Attention) Success
EXEC sp_trace_setevent @TraceID, 16, 25, 1; -- EventClass (SP:Attention) IntegerData
EXEC sp_trace_setevent @TraceID, 16, 27, 1; -- EventClass (SP:Attention) EventClass
EXEC sp_trace_setevent @TraceID, 16, 31, 1; -- EventClass (SP:Attention) Error Number
EXEC sp_trace_setevent @TraceID, 16, 34, 1; -- EventClass (SP:Attention) ObjectName
EXEC sp_trace_setevent @TraceID, 16, 49, 1; -- EventClass (SP:Attention) RequestID
EXEC sp_trace_setevent @TraceID, 16, 55, 1; -- EventClass (SP:Attention) IntegerData2
EXEC sp_trace_setevent @TraceID, 40, 1, 1; -- EventClass (SP:StmtStarting) TextData
EXEC sp_trace_setevent @TraceID, 40, 4, 1; -- EventClass (SP:StmtStarting) TransactionId
EXEC sp_trace_setevent @TraceID, 40, 9, 1; -- EventClass (SP:StmtStarting) ClientProcessID
EXEC sp_trace_setevent @TraceID, 40, 10, 1; -- EventClass (SP:StmtStarting) ApplicationName
EXEC sp_trace_setevent @TraceID, 40, 11, 1; -- EventClass (SP:StmtStarting) LoginName
EXEC sp_trace_setevent @TraceID, 40, 12, 1; -- EventClass (SP:StmtStarting) SPID
EXEC sp_trace_setevent @TraceID, 40, 13, 1; -- EventClass (SP:StmtStarting) ClientProcessID
EXEC sp_trace_setevent @TraceID, 40, 14, 1; -- EventClass (SP:StmtStarting) StartTime
EXEC sp_trace_setevent @TraceID, 40, 15, 1; -- EventClass (SP:StmtStarting) EndTime
EXEC sp_trace_setevent @TraceID, 40, 20, 1; -- EventClass (SP:StmtStarting) Severity
EXEC sp_trace_setevent @TraceID, 40, 23, 1; -- EventClass (SP:StmtStarting) Success
EXEC sp_trace_setevent @TraceID, 40, 25, 1; -- EventClass (SP:StmtStarting) IntegerData
EXEC sp_trace_setevent @TraceID, 40, 27, 1; -- EventClass (SP:StmtStarting) EventClass
EXEC sp_trace_setevent @TraceID, 40, 31, 1; -- EventClass (SP:StmtStarting) Error Number
EXEC sp_trace_setevent @TraceID, 40, 34, 1; -- EventClass (SP:StmtStarting) ObjectName
EXEC sp_trace_setevent @TraceID, 40, 49, 1; -- EventClass (SP:StmtStarting) RequestID
EXEC sp_trace_setevent @TraceID, 40, 55, 1; -- EventClass (SP:StmtStarting) IntegerData2
EXEC sp_trace_setevent @TraceID, 41, 1, 1; -- EventClass (SP:StmtCompleted) TextData
EXEC sp_trace_setevent @TraceID, 41, 4, 1; -- EventClass (SP:StmtCompleted) TransactionId
EXEC sp_trace_setevent @TraceID, 41, 9, 1; -- EventClass (SP:StmtCompleted) ClientProcessID
EXEC sp_trace_setevent @TraceID, 41, 10, 1; -- EventClass (SP:StmtCompleted) ApplicationName
EXEC sp_trace_setevent @TraceID, 41, 11, 1; -- EventClass (SP:StmtCompleted) LoginName
EXEC sp_trace_setevent @TraceID, 41, 12, 1; -- EventClass (SP:StmtCompleted) SPID
EXEC sp_trace_setevent @TraceID, 41, 13, 1; -- EventClass (SP:StmtCompleted) ClientProcessID
EXEC sp_trace_setevent @TraceID, 41, 14, 1; -- EventClass (SP:StmtCompleted) StartTime
EXEC sp_trace_setevent @TraceID, 41, 15, 1; -- EventClass (SP:StmtCompleted) EndTime
EXEC sp_trace_setevent @TraceID, 41, 20, 1; -- EventClass (SP:StmtCompleted) Severity
EXEC sp_trace_setevent @TraceID, 41, 23, 1; -- EventClass (SP:StmtCompleted) Success
EXEC sp_trace_setevent @TraceID, 41, 25, 1; -- EventClass (SP:StmtCompleted) IntegerData
EXEC sp_trace_setevent @TraceID, 41, 27, 1; -- EventClass (SP:StmtCompleted) EventClass
EXEC sp_trace_setevent @TraceID, 41, 31, 1; -- EventClass (SP:StmtCompleted) Error Number
EXEC sp_trace_setevent @TraceID, 41, 34, 1; -- EventClass (SP:StmtCompleted) ObjectName
EXEC sp_trace_setevent @TraceID, 41, 49, 1; -- EventClass (SP:StmtCompleted) RequestID
EXEC sp_trace_setevent @TraceID, 41, 55, 1; -- EventClass (SP:StmtCompleted) IntegerData2
-- Step 3: Set a filter for the table CommandOrderParts
EXEC sp_trace_setfilter @TraceID, 55, 0, 6, N'dbo.CommandOrderParts'; -- ObjectName filter
-- Optional: Add a filter for ApplicationName to capture specific applications
EXEC sp_trace_setfilter @TraceID, 10, 0, 6, N'File_App1'; -- Filter for File_App1.dll
EXEC sp_trace_setfilter @TraceID, 10, 1, 6, N'File_App2'; -- Filter for File_App2.dll
-- Step 4: Start the trace
EXEC sp_trace_setstatus @TraceID, 1; -- Start the trace
-- Step 5: Stop the trace
EXEC sp_trace_setstatus @TraceID, 0; -- Stop the trace
Obviously, I start executing this SQL script until step 4. If I want the script to stop, I launch step 5.
Oh, before I forget: the script I first found contained other values for the events. I ran the SQL query SELECT @@VERSION
and as the result was Microsoft SQL Server 2017 (RTM-CU31-GDR) (KB5029376) ...
, I decided to go to this page in order to get the events' definitions:
Edit concerning deadlock-sensitivity
Just for your information: the application seems to be deadlock-sensitive: In a timeframe of not even six months, I have found 213 deadlock-related exceptions like this one:
2024-10-28 12:53:31.5199 | Error | App1.RaiseConnectionFailed | Telerik.OpenAccess.RT.sql.SQLException: Transaction (Process ID 76) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction. ---> System.Data.SqlClient.SqlException: Transaction (Process ID 76) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)
at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more)
at System.Data.SqlClient.SqlDataReader.Read()
at OpenAccessRuntime.Intellitrace.Read(DbDataReader reader, String id)
at Telerik.OpenAccess.Runtime.Logging.LoggingDbDataReader.Read()
at Telerik.OpenAccess.RT.Adonet2Generic.Impl.ResultSetImp.next()
--- End of inner exception stack trace ---
at Telerik.OpenAccess.RT.Adonet2Generic.Impl.ResultSetImp.next()
at OpenAccessRuntime.Relational.fetch.FetchResultImp.rsNext()
at OpenAccessRuntime.Relational.fetch.FetchResultImp.hasNext()
The public FireChanging
method invokes evChanging
with ChangeEventArgs
. It is likely the method sets ChangeEventArgs.Cancel
to true
to indicate the old/new values are different (a concurrency violation) in order to avoid the race condition and silently overwrite existing database values. The change operation cancelled by user message is a bit misleading in this case. A better message would be something like Operation cancelled because data was changed by another user.
Concurrency issues are a matter of timing and can be problematic to troubleshoot. You need to have application logs and/or SQL tracing detailed enough to correlate the error with requests that try to modify the same data at the same time. The resolution may require changes to the application (e.g. allow user to refresh/retry) or process engineering to avoid attempts to modify the same row concurrently.