Slow read from SqlDataReader #1206
Comments
|
@valentiniliescu Hi, Logs are not saying much in this case, What I understood from the log: Is it possible to make a repro including the connection string (including the options you are using) and the query that you run? |
|
Unfortunately, I cannot create a repro, but this is the sanitized version of the code that we run: var connectionString = string.Format("Data Source={0};Initial Catalog={1};Connection Timeout={2}", "server", "database", "240");
using SqlConnection connection = new SqlConnection(connectionString);
await connection.OpenAsync().ConfigureAwait(false);
using SqlCommand command = new SqlCommand("[dbo].[MyStoredProc]", connection);
command.CommandTimeout = 240;
command.CommandType = CommandType.StoredProcedure;
command.Parameters.Add(new SqlParameter("@Param1", SqlDbType.NVarChar) { Value = "value1" });
command.Parameters.Add(new SqlParameter("@Param1", SqlDbType.Int) { Value = 1 });
using SqlDataReader reader = await command.ExecuteReaderAsync(CommandBehavior.SequentialAccess).ConfigureAwait(false);
while (await reader.ReadAsync().ConfigureAwait(false))
{
string col1 = await reader.GetTextReader(0).ReadToEndAsync().ConfigureAwait(false);
double col2 = decimal.ToDouble((decimal)reader.GetValue(1));
}I used the managed SNI only for tracing purposes, otherwise I don't see SNI traces in the logs. Also, this is an Azure Function, so there might be concurrent runs, but, as you can see from the code snippet above, there are no shared objects. |
|
Are you reading large strings or binary when the problem occurs? |
|
No, the strings are pretty small. For example, for this particular query, the result is 12000 rows, with one column NVARCHAR and each value 25-30 characters and one DECIMAL(6,5) |
|
@valentiniliescu I made a Benchmark testing for this matter. The sample code could be found in this gist. I have tested different scenarios.
The results are as below: // * Summary * BenchmarkDotNet=v0.13.0, OS=Windows 10.0.19043.1151 (21H1/May2021Update) Job=.NET Core 3.1 Runtime=.NET Core 3.1
It seems reading with Sequential access is causing the delay. Can you test it please? For those who want to follow: Run the following script on SSMS and make a database with 12000 rows DECLARE @RowAmount AS INT = 12000;
WITH InfiniteRows (RowNumber1, RowNumber2) AS (
SELECT 1 AS RowNumber1, 2 AS RowNumber2
UNION ALL
SELECT a.RowNumber1 +1 AS RowNumber1, a.RowNumber2+1 AS RowNumber2
FROM InfiniteRows a
WHERE a.RowNumber1 < @RowAmount
)
SELECT CONVERT(NVARCHAR(255), NEWID()) AS VAL1, RowNumber1/3.3000 *100.00 AS VAL2
INTO temp
FROM InfiniteRows
OPTION (MAXRECURSION 0);
GOto create Stored procedure: CREATE PROCEDURE MyStoredProc
@Param1 nvarchar (max),
@Param2 decimal (26,8)
AS
BEGIN
SELECT * from temp
ENDCan you also confirm that the stored procedure is something similar to what you have? |
|
Thank you @JRahnama for your code and benchmark. For the stored procedure, mine is pretty complicated, but the shape and count of the result is pretty similar. At this point I am going to try a workaround - to reduce the size of the results from the stored procedure, so the random slowness in the TDS packets will not influence that much. |
cheenamalhotra
added
the
📈 Performance
JRahnama
added
the
✔️ Repro Available
|
I've done some investigation. The difference in speed between sequential and non-sequential reads is caused by the extra overhead of using an For the case where individual reads are extremely slow there isn't much that can be done without a reproduction. |
|
Related to #593 |
Describe the bug
We have an issue with an Azure Function that runs a query against a Azure SQL Server. The function uses a SqlDataReader, and the command / query execution is pretty fast, but reading the results is sometimes slow. It does not happen very often, but when it happens, there is a certain pattern, the TDS packets seem to be delayed. For example, this is a log snippet:
If I understand the log correctly, there is a ~250ms delay when receiving the TDS packet, and, for this particular query, there are 100 packets which adds up to 20-30 seconds.
This seems to happen sporadically without any clear cause. Also, the SQL server isn't busy at all at this time (<5% CPU and IO usage).
Further technical details
Microsoft.Data.SqlClient version: 3.0.0
.NET target: Core 3.1
SQL Server version: Azure SQL Server
Operating system: Azure Function v3 on Windows
The text was updated successfully, but these errors were encountered: