MarkMpn / Sql4Cds

SQL 4 CDS core engine and XrmToolbox tool
MIT License
74 stars 22 forks source link

MarkMpn.Sql4Cds.Engine.Sql4CdsException: 'Operation cancelled by user.' #485

Open sybaris opened 2 months ago

sybaris commented 2 months ago

Hi,

Since I migrate from MarkMpn.Sql4Cds.Engine 8.0 to 9.1 on my tool, I have the following error (even in debug mode, or in release...) :

image

I tried to extract a query or a part of my program to reproduce, but I fail on each try.

I am very interested to migrate to 9.1, because you fix some very usefull things, but this issue blocks me.

If this information is enough for you to correct the issue, great, but in my opinion you need more information. If you have any ideas to guide me in isolating this problem, please don't hesitate...

Regards Sybaris

sybaris commented 2 months ago

Note that with the following code (after creating Sql4CdsConnection), I do not have the issue : UseTDSEndpoint = false;

MarkMpn commented 2 months ago

It's trying to retrieve a list of tables from the TDS Endpoint to check if your query is compatible with it, and it looks like you're hitting some sort of error during that check.

sybaris commented 2 months ago

- Does the error happen immediately or is it after some timeout period? It's after a timeout period. I run many "heavy" queries. - Can you connect to the TDS Endpoint from this same machine with SSMS or similar and execute the query ? Done successfully (with SSMS & Sql4Cds) . Result is displayed quickly < 1 second for 1518 rows.

Another thing interesting : Instead of making UseTDSEndpoint = false; I do CommandTimeout = 60 * 5; // 5 minuts on all Sql4CdsCommand, I do not have the error any more.

So if I understand, when I use tds, "Operation cancelled by user" error is more a timeout, isn't it ?

MarkMpn commented 2 months ago

The command timeout from the Sql4CdsCommand should only apply once it starts actually running the query, but the stack trace shown indicates it is occurring while it is still building the execution plan. This stage should also not take over the 30 seconds defined by the default command timeout.

Is there anything more you can share about your app and the queries it is running to help me reproduce this?

sybaris commented 2 months ago

The query that timeout is like this :

select '%Object reference not set to an instance of an object%' as ExceptionName, SUBSTRING(typename, 1, CHARINDEX(',', typename)-1) as TypeName, count(*) as Count
from plugintracelog
where createdon between '2024 -06-14 00:00:00' and '2024 -06-17 00:00:00'
and  exceptiondetails like '%Object reference not set to an instance of an object%' 
group by typename
order by 3 desc

On this environment, for example, we have 150 000 rows (all exceptions) in plugintracelog for this period.

and I loop to detect the following text on exceptions :

                "%Object reference not set to an instance of an object%",
                "%Stream was not readable%",
                "%Input string was not in a correct format%",
                "%Cannot update Closed or Cancelled Activity%",
                "%The given key was not present in the dictionary%",
                "%is not a valid status code for state code%",

But what I noticed is that this happens during my first attempts, but after several reties, often, it ends up working, and after that the request no longer times out. Until the next day, when I change my period, then it does it again...

MarkMpn commented 2 months ago

Is it possible this is something like the server shutting things down when they're not being used overnight and taking a while to start back up in the morning? If you connect with SSMS first thing in the morning before running your app, does it take a long time to connect?

sybaris commented 2 months ago

Difficult to confirm or not. Today for example not reproduced. Give me a few days to do some more tests, and try to get a little more info...

MarkMpn commented 1 month ago

Did you manage to make any more progress investigating this?

sybaris commented 1 month ago

Hi,

I have duplicated my pipeline that execute these queries.

My first pipeline get an exception with the message "Query timed out" from MarkMpn.Sql4Cds.Engine.Sql4CdsDataReader.Read() after 30 seconds. Note that ExecuteReader() ends after 4 720 ms.

And no problem with second pipeline...

I don't know what other tests can I do ?

Regards Sybaris