sp_executesql & XE - different #logical reads for sp_statement_completed and rpc_completed, what can be the cause?

Question

We have a client application that uses sp_executesql to execute queries. The queries are parameterized. When we monitor via Extended Events, we regularly see a difference between the number of logical reads between the sp_statement_completed and rpc_completed. The majority of cases has an equal number of logical reads. The difference is significant, e.g. 3000 versus more than 10000. The duration is also significantly lower in these cases, e.g. 20 ms versus 200 ms. What can be the cause of that? I mean, some sort of overhead in sp_executesql, then I would expect to see a difference in most cases, but that is not so. Note as well these queries all use the same plan (same plan handle, also same query hash). Could it be for example a recompile? I don't know the internals of SQL Server for that, but I wondered whether a recompile could result internally in logical reads and that it would explain the difference? Another cause?

Answer 1

Hi @PetervdH ,

Welcome to Microsoft Q&A!

Could you please provide some snapshots of your Extended Events or one example of your queries?

You could refer to below actors which may cause the significant difference of logical reads or duration and check whether any of them is helpful.

• Your queries might include more than one sql statement.
• Frequency with the query/batch/procedure is called.
• Recompile.
• Size of related tables and results return.
• Performance of your memory/disk.
• Indexes or statistics on the related tables.
• Network or protocol.

Best regards,
Melissa

---

If the answer is the right solution, please click "Accept Answer" and kindly upvote it. If you have extra questions about this answer, please click "Comment". 
Note: Please follow the steps in our documentation to enable e-mail notifications if you want to receive the related email notification for this thread.

Answer 2

Hi ErlandSommarskog,

I am researching an existing database and situation that I am totally new at, so I am taking things step by step. Didn't want to activate too many sort of traces from the start in a production system under high pressure. I suspected myself also a recompile, but wanted to find out if someone knew that indeed this would show up as extra logical reads for the whole sp_executsql. I have by now run XE including the auto_stats event and found out the following:

(1) There is a small table part of the query (the query is quite large, close to 20 joins) that is used in such a way apparently that constantly inserts and deletes take place and remains a bit around 500 rows. So, the threshold for update statistics is constantly hit. This caused the almost continuous recompiles of the query plan.

(2) About whether the auto stats are included in the sp_statement, I don't know. What I have seen so far, is that the duration and cpu_time of the sp_statement_completed are in line with all the times the query is executed without the recompile. Perhaps the difference for that in duration and cpu_time is not that easily measurable.

I was also sidetracked a bit about Micorsoft SQL Server documentation on usecounts (cached plans) and creation_time (query stats). I think their descriptions are incorrect.

Thank you for your reply.

Answer 3

Hi Melissa,

thank you very much for your response. See attached file, these are all about the same query, the query is executed via sp_executesql and is parameterized. I cannot include the query itself because of company security reasons. As you can see also the query hash and plan handle are the same. I can assure you the statements and sql text are the same as well (apart from different parameter values). See my remarks below to your points.

Your queries might include more than one sql statement.
**>> That is not the case. It is one query only.

Frequency with the query/batch/procedure is called.
**>> I am not sure what you mean with this. It is a single call using sp_executesql.

Recompile.
**>> This is what I wondered. If a recompile would have happened, is it then so, that the number of logical reads for the sp_executesql can be higher than the sp_statement, because of SQL Server internal things?

Size of related tables and results return.
**>> Number of rows is same for sp_statement and rpc (see attached picture). Since it is one query only with sp_executesql it would even worse if that would be different :)

Performance of your memory/disk.
**>> How can that make a difference in logical reads?

Indexes or statistics on the related tables.
**>> Execution plan is the same for all of the ones I showed in the attached picture, but even if SQL server would do something different, it would not explain the difference in logical reads between the sp_statement and the rcp?

Network or protocol.
**>> All the same.

So, just to be sure, I am not talking about a difference in logical reads for the different executions, that is normal, it is about different parameters values, etc. I am talking about the difference in logical reads between the sp_statement and rpc (which is the sp_executesql).

Answer 4

Melissa, one more thing about your point "Indexes or statistics on the related tables". Do you mean, that if SQL server would decide to calculate statistics (auto stats is switched on in our case), that in that case the logical reads for the rpc (sp_executesql) would be higher than for the sp_statement?

Answer 5

I think the most likely answer is compilation. That time is not included in sp_statement_completed, but it will be included in rpc_completed.

Autostats on the other hand are included in sp_statement_completed, as I recall. And you would see autostats as separate statements. (At least you do in Trace, which I prefer to use for this sort of thing.)