ILLBLGenProQuery.ExecuteAsync not passing through CancellationToken

Posts   
1  /  2
 
    
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 13-Oct-2022 06:39:35   

While investigating why Async queries where not getting cancelled I looked through the LLBL source and found what appears to be the problem:

        Task<object> ILLBLGenProQuery.ExecuteAsync(CancellationToken cancellationToken)
        {
            return this.ExecuteAsync<object>(CancellationToken.None);
        }

In both LLBLGenProQuery.cs and DataSourceBase.cs.

V5.9.2

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 13-Oct-2022 08:25:47   

flushed will fix it. Sorry about that.

Frans Bouma | Lead developer LLBLGen Pro
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 13-Oct-2022 09:53:10   

Fixed in 5.8.7 and 5.9.3 hotfix builds which are now available

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 14-Oct-2022 06:16:40   

Yep that sorted it thanks.

Still not getting a 'Operation cancelled by user.' SqlException but that could be a problem my end, still looking...

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 14-Oct-2022 07:38:08   

TomDog wrote:

Yep that sorted it thanks.

Still not getting a 'Operation cancelled by user.' SqlException but that could be a problem my end, still looking...

I checked whether it wasn't propagated elsewhere but this was the only spot that I could see. Let me know if you find another flaw in the call chain (as with linq it can be quite long so perhaps somewhere it makes a wrong turn which goes unnoticed in tests unless you cancel all queries in all tests to see if the call paths are indeed connected)

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 17-Oct-2022 09:11:24   

In my sandpit DataAccessAdapter.ExecuteSQLAsync("WAITFOR DELAY '00:00:12'") is getting cancelled but QuerySpec isn't e.g. DataAccessAdapter.FetchScalarAsync

e.g. asp.net mvc framework action

    public Task<JsonNetResult> ExecuteSQLAsync(string sqlQuery, object parameterValues = null)
    {
      return JsonNetAsync(DataSingletons.PortalDataAccessAdapter.ExecuteSQLAsync(Response.ClientDisconnectedToken, sqlQuery, parameterValues));
    }

    public async Task<JsonNetResult> QueryFactoryCountAsync()
    {
      var qf = new QueryFactory();
      var q = qf.SafetyOccurrence.Where(SafetyOccurrenceFields.Description.Contains("123"));
      var count = await DataSingletons.PortalDataAccessAdapter.FetchScalarAsync<int>(qf.Create().Select(q.CountRow()), Response.ClientDisconnectedToken);
      return JsonNet(count);
    }
Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 17-Oct-2022 09:50:41   

Will check it. Thanks for the repro!

Frans Bouma | Lead developer LLBLGen Pro
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 17-Oct-2022 10:17:06   

I followed the cancellation token through the entire call path but it's passed on properly to the DbCommand. Perhaps the query is too fast before you can cancel it?

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 18-Oct-2022 05:46:13   

Getting closer, this cancels:

      var retrievalQuery = DataSingletons.PortalDataAccessAdapter.CreateRetrievalQueryFromSQL(sqlQuery, null);
Response.ClientDisconnectedToken)
      var result =  await retrievalQuery.ExecuteScalarAsync(Response.ClientDisconnectedToken);

This does not

      var retrievalQuery = DataSingletons.PortalDataAccessAdapter.CreateRetrievalQueryFromSQL(sqlQuery, null);
Response.ClientDisconnectedToken)
      var result =  await retrievalQuery.ExecuteAsync(CommandBehavior.Default, Response.ClientDisconnectedToken);

but why I have no idea

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 18-Oct-2022 09:58:12   

The latter hasn't read from the data yet, you first have to do a Read() on the returned datareader, which might be the issue. Another thing might be that we don't use ReadAsync() on the datareaders but Read(), as the Read() is likely to be synchronous anyway (due to the buffered nature of a datareader).

I have to admit, it might be the async implementation in the tight datareader loops is perhaps a bit off in our runtime, as in: we don't check the cancellation token in the tight loop over the datareader, we leave cancellation solely to the DbCommand.ExecuteAsync method. So if that method returns a reader successfully, cancellation can't occur anymore (as the reads are synchronous and we don't check the cancellation token).

So not sure what query you tested here, should the query return a reader on a resultset immediately or did you use the waitfor query in the second call which failed? (in which case the query wouldn't return and cancellation should be possible).

Frans Bouma | Lead developer LLBLGen Pro
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 18-Oct-2022 10:16:41   

I've changed the DbDataReader.Read() into ReadAsync in two places (it's not much code) to see if that fixes anything for you.

I do have a hard time coming up with a test that reliably tests this tho...

There are several problems in SqlClient associated with ReadAsync(), additionally to issues like this one: https://github.com/dotnet/SqlClient/issues/593 (which is still open) so I'm a bit reluctant to proceed with this in a bugfix release.

I've attached temp builds of the assemblies for the sqlserver dqe and the ormsupportclasses with readasync() instead of read() on the datareaders to see if that fixes your issue. (this is 5.9.3 hotfix, but should be a drop in replacement for 5.9.2 )

Attachments
Filename File size Added on Approval
593_Hotfix_RuntimesNetFx.zip 602,126 18-Oct-2022 10:45.04 Approved
593_Hotfix_RuntimesNetStandard.zip 599,123 18-Oct-2022 10:45.56 Approved
Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 18-Oct-2022 12:26:47   

Adding a ReadAsync in throws Operation cancelled by user. exception on the ReadAsync. This example is just straight ADO Exception is visible in ORM profiler

      var dbConnection = DataSingletons.PortalDataAccessAdapter.GetActiveConnectionPublic();
      await dbConnection.OpenAsync(Response.ClientDisconnectedToken).ConfigureAwait(AQDConstants.ContinueOnCapturedContext);
      var reader = await DataHelper.ExecuteReaderAsync(dbConnection, DataSingletons.PortalDataAccessAdapter.PhysicalTransactionPublic, sqlQuery, CommandType.Text, Response.ClientDisconnectedToken)
        .ConfigureAwait(AQDConstants.ContinueOnCapturedContext);
      var result = await reader.ReadAsync(Response.ClientDisconnectedToken).ConfigureAwait(AQDConstants.ContinueOnCapturedContext);

Unfortunately ReadAsync throwing the exception isn't a whole lot of use as it doesn't happen till after the query returns, i.e. it doesn't abort the query.

In this example ExecuteReaderAsync does - https://dotnetfiddle.net/o8c20l

Worth a read https://www.roji.org/db-commands-and-cancellation

The dll's you attached still didn't throw any exception though.

The SQl I'm running takes about 3 seconds

SELECT TOP(1 /* @p2 */) COUNT(*) AS [LPAV_]
FROM   [AQD].[saf_Occurrence] [LPLA_1]
WHERE  (((([LPLA_1].[Description] LIKE '%123%' /* @p3 */))))
Jeremy Thomas
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 18-Oct-2022 13:56:47   

Found a problem, if I turn ORMProfiler off i.e.. <add key="ORMProfilerEnabled" value="false" /> ExecuteReaderAsync now does cancel

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 18-Oct-2022 15:53:31   

Hmm, so the changes I made weren't of great help. I didn't expect them to be of much help (as ReadAsync on a reader really has to pull in a lot of data to make a difference), but it wouldn't hurt to try. I'll roll back the changes.

From your last message I understand it's mainly caused by orm profiler's interception? Or do you want me to check something else? (as I don't know what might cause these problems disappointed )

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 18-Oct-2022 17:53:20   

The two things I can think are

  • Fix the ORM Profiler interceptor to pass through the token

  • Check the cancellation token in the tight loop over the datareader

Neither of those will make the cancelation happen when I use the LLBL methods but might make it easier to find out what's going on.

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 19-Oct-2022 09:23:32   

TomDog wrote:

The two things I can think are

  • Fix the ORM Profiler interceptor to pass through the token

will do

  • Check the cancellation token in the tight loop over the datareader

This is something the ReadAsync(cancellationToken) already did I think, i.e. the change I made in the dll's above: ReadAsync() checks the cancellation token and returns a completed task with cancelled set if a cancellation is requested. But I'll check if that requires code on my part.

Looking into it, SqlDataReader.ReadAsync() doesn't thrown OperationCancelledException() when the operation is cancelled, but ... so doesn't SqlCommand.ExecuteReaderAsync(). They return a cancelled task.

Which seems to be confirmed here: https://github.com/dotnet/SqlClient/issues/1065#issuecomment-836999612

This has been changed in the latest Microsoft.Data.SqlClient (15 days ago): https://github.com/dotnet/SqlClient/blob/main/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlDataReader.cs#L4740, i.o.w. if the token has expired / is cancelled it will cause the query to be cancelled. System.Data.SqlClient won't do this, it will return a completed task, (in some cases, see the issue above).

This too doesn't throw any exception btw. It simply makes sure DbCommand.Cancel() is called.

So to recap, what I could do is check if the cancellation token can be cancelled, if so, register a callback to the DbCommand.Cancel(), and inside the while loop if the token has been cancelled return a Task.FromCancelled<bool>(token) or similar (as of course neat code isn't added anymore to netfx).

This all also might be the indication why you see what you're seeing in your tests.

Frans Bouma | Lead developer LLBLGen Pro
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 19-Oct-2022 11:09:51   

ORM Profiler has been updated. Will now look into making our Read methods more adaptive to cancellation in async scenarios

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 19-Oct-2022 12:43:43   

Otis wrote:

ORM Profiler has been updated.

Yep working for me now though the profiler is still not showing the exception in the alert column, but that has always been intermittent.

And I don't know what happened but now Linq CountAsync is throwing OperationCancelledException on the read

Still not on the ExecuteReaderAsync though.

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 19-Oct-2022 15:57:02   

I've pushed a hotfix build for 5.8.7 and 5.9.3 which should take care of the cancellation token handling inside the two loops which consume the datareader on async paths. It'll cancel the query and return a cancelled task in the projection path and simply stop consuming data in the entity path (as we can't return a cancelled task on a method which does awaits).

This won't throw exceptions as that's not what should be done (SqlClient also doesn't throw exceptions). As Microsoft has fixed this issue 2 weeks ago in Microsoft.Data.Client and won't port it back to netfx I think this is a good solution for the problem when you want to cancel a query with a big resultset

Now back to what you run into: it's my understanding that SqlClient doesn't throw an exception (we don't as well) when operations are cancelled. Definitely not on the reader path. CountAsync does an executescalarasync which also doesn't throw an exception. So it's a bit odd you run into that... it gives you a stacktrace which offers a location?

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 20-Oct-2022 11:23:34   

From ORM Profiler running my ADO code

Exception type: System.Data.SqlClient.SqlException
Message: A severe error occurred on the current command.  The results, if any, should be discarded.
Operation cancelled by user.

Stack-trace:
   at System.Data.SqlClient.SqlCommand.<>c.<ExecuteDbDataReaderAsync>b__180_0(Task`1 result)
   at System.Threading.Tasks.ContinuationResultTaskFromResultTask`2.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at SD.Tools.OrmProfiler.Interceptor.ProfilerDbCommand.<ExecuteDbDataReaderAsync>d__13.MoveNext()
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext, ContextCallback, Object, Boolean)
   at System.Threading.ExecutionContext.Run(ExecutionContext, ContextCallback, Object, Boolean)
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore+MoveNextRunner.Run()
   at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(Action, Boolean, Task&)
   at System.Threading.Tasks.Task.FinishContinuations()
   at System.Threading.Tasks.Task.Finish(Boolean)
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task&)
   at System.Threading.Tasks.Task.ExecuteEntry(Boolean)
   at System.Threading.Tasks.ThreadPoolTaskScheduler.TryExecuteTaskInline(Task, Boolean)
   at System.Threading.Tasks.TaskScheduler.TryRunInline(Task, Boolean)
   at System.Threading.Tasks.TaskContinuation.InlineIfPossibleOrElseQueue(Task, Boolean)
   at System.Threading.Tasks.Task.FinishContinuations()
   at System.Threading.Tasks.Task.Finish(Boolean)
   at System.Threading.Tasks.Task`1.TrySetException(Object)
   at System.Threading.Tasks.UnwrapPromise`1.TrySetFromTask(Task, Boolean)
   at System.Threading.Tasks.UnwrapPromise`1.ProcessInnerTask(Task)
   at System.Threading.Tasks.UnwrapPromise`1.ProcessCompletedOuterTask(Task)
   at System.Threading.Tasks.UnwrapPromise`1.Invoke(Task)
   at System.Threading.Tasks.Task.FinishContinuations()
   at System.Threading.Tasks.Task.Finish(Boolean)
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task&)
   at System.Threading.Tasks.Task.ExecuteEntry(Boolean)
   at System.Threading.ThreadPoolWorkQueue.Dispatch()

You can also see it running this in LinqPad (based off https://dotnetfiddle.net/o8c20l)

var w = new Stopwatch();
var con = new SqlConnection(@"Data Source=(localdb)\MSSQLLocalDB;Initial Catalog=master;Integrated Security=True;");
con.GetType().AssemblyQualifiedName.Dump();
await con.OpenAsync();
var ts = new CancellationTokenSource(TimeSpan.FromSeconds(5));
var command = con.CreateCommand();
command.CommandText = "WAITFOR DELAY '00:01'";
try
{
    w.Start();
    await command.ExecuteReaderAsync(ts.Token);
}
catch (SqlException e)
{
    w.Stop();
    Console.WriteLine("Cancelled:" + w.Elapsed);
    Console.WriteLine("Cancelled:" + e);
}
Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 21-Oct-2022 09:12:21   

Isn't that coming from the Cancel on the command? What I'm puzzled with is what there is left for us to change/fix simple_smile. There's sadly no agreement on how to handle this inside .net: ADO.NET seems to lean towards silently cancelling simply because it would otherwise kill the connection so a retry won't work without reconnecting, but other code seems to suggest you can just throw an OperationCancelledException when cancellation occurs. I think in this light what should be done in our code at least is never throw but cancel the operations if possible.

In my knowledge there's little else we can do at this point: the cancellation token is passed on, in the reader consumption code in our runtime we check the token and if it's cancelled we abort the loop and cancel the command (what ReadAsync also seems to do). (this is in the hotfix I pushed 2 days ago).

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 21-Oct-2022 12:03:35   

Your changes to the reader are working for me - a LLBL LINQ query is now aborting the query early and then throwing a cancelation exception on a read, thankyou!

I now see two different behaviours with command.ExecuteReaderAsync: when running WAITFOR DELAY it throws a Operation cancelled by user SqlException like ExecuteNonQueryAsync or ExecuteScalarAsync does but for normal retrieval queries if cancels silently. WTF!

Anyway what you have done seems to echo what reader.ReadAsync does so yes I agree, nothing more for you to do.

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 22-Oct-2022 09:06:01   

TomDog wrote:

Your changes to the reader are working for me - a LLBL LINQ query is now aborting the query early and then throwing a cancelation exception on a read, thankyou!

Nice! simple_smile

I now see two different behaviours with command.ExecuteReaderAsync: when running WAITFOR DELAY it throws a Operation cancelled by user SqlException like ExecuteNonQueryAsync or ExecuteScalarAsync does but for normal retrieval queries if cancels silently. WTF!

Hmm, that's indeed very weird! Could it be the WAITFOR query doesn't produce a resultset and therefore no stream? You might want to take this up with the SqlClient team on github, they might know the reason simple_smile

Anyway what you have done seems to echo what reader.ReadAsync does so yes I agree, nothing more for you to do.

simple_smile Thank you for bringing this up and I'm happy with the end result being fast and tidy simple_smile

Frans Bouma | Lead developer LLBLGen Pro
TomDog
User
Posts: 620
Joined: 25-Oct-2005
# Posted on: 06-Dec-2022 00:28:03   

I've finally had a chance to get back to this and I think I might have put you a bit wrong.

From what I have observed: All SQLCommand async methods will throw SqlException or a TaskCanceledException when the token is cancelled, apart from ExecuteReaderAsync when the query does not have a WAITFOR DELAY 'xx:yy' in it - in which case it just cancels silently. In the case of the ExecuteReaderAsync cancelling silently if the resulting DbDataReader subsequently calls Read or ReadAsync(without the token) it also throws a SqlException, if ReadAsync is called with the cancelled token it throws a TaskCanceledException. If the token is cancelled after the first read then all remaining reads will continue except for ReadAsync(with the token) which throws a TaskCanceledException

From what I can see with what you've done if a task gets cancelled after the first read it aborts the reading silently with the number of rows read so far. I.e. the consumer gets some of the rows back but with no indication that it got aborted which isn't ideal.

To make your ReadAsync behave like DbDataReader ReadAsync I propose you first call cancellationToken.ThrowIfCancellationRequested(); then while reading the results call that rather than exiting the loop.

What do you think?

Jeremy Thomas
Otis avatar
Otis
LLBLGen Pro Team
Posts: 39740
Joined: 17-Aug-2003
# Posted on: 06-Dec-2022 09:43:28   

Doesn't that go against what I described here above? https://www.llblgen.com/tinyforum/Message/Goto/151182

Frans Bouma | Lead developer LLBLGen Pro
1  /  2