How applications cause excessive ASYNC_NETWORK_IO waits in SQL Server

In this post I’ll go over what the ASYNC_NETWORK_IO wait type is, when it occurs, and how you can tell if the application is causing it.

Lately I’ve had to troubleshoot a few situations where the issue seemed like a poor performing query, but the apparent slowdown was due to applications causing excessive ASYNC_NETWORK_IO waits in SQL Server.

What is ASYNC_NETWORK_IO?

When SQL Server has to return the result set for a query it provides that data to the client application (regardless if the client is SSMS, sqlcmd, or any other app) by putting the result set in an output buffer and waiting for the client application to ingest the result set and acknowledge that it has consumed the data.

The time between the moment when SQL Server makes the result set available in the output buffer and the moment when the client application acknowledges that it has consumed it will be recorded as an ASYNC_NETWORK_IO wait.

When does this wait occur?

Application server under load

If the application server’s resources (I/O, RAM, CPU) are maxed out, the application can end up having to stall due to not having enough resources available to receive and process the result set.

Large result set

If the query returns a large result set comprised of millions of records that add up to multiple GB of data, then it’s pretty much inevitable to notice some ASYNC_NETWORK_IO wait times.

I’ve even caused this wait myself by running queries that retrieved upwards of 10GB of data.

Even if you’re using SSMS from a VM with lots of resources, there’s only so much bandwidth to handle the data transfer.
Plus SSMS starts taking a while to render the rows when you get past a certain number.

Network issues

If the network is slow or drops packets, the client application will end up taking longer to retrieve the result set and thus will make SQL Server wait longer for the acknowledgement that it has received the data.

There’s a good Microsoft Learn article about troubleshooting each of these scenarios.

The application does not ingest the result set fast enough

This tends to happen when the application doesn’t retrieve the whole result set in one go, but, in stead, it processes the result set in small batches of rows by applying some business logic before either writing that that batch of rows to an output file or writing it back to the database, and advancing through the result set batch by batch in the same fashion.

So, while SQL Server keeps the session active waiting for the application to ingest the result set, the application does the following:

Grabs a fairly small batch of rows (it can even be one row)
Makes SQL Server wait while it processes that batch
Grabs the next batch and repeats the processes

Rinse and repeat until the whole result set has been processed.

Meanwhile, on the SQL Server side, the ASYNC_NETWORK_IO keeps increasing, while the end user gets the feeling that nothing is happening and that SQL Server is having a hard time processing the query.

And the larger the result set, the longer the total ASYNC_NETWORK_IO wait times will get.

This is the root cause I’ll be focusing on in this post.

Causing excessive ASYNC_NETWORK_IO waits in SQL Server

For this demo I’ve opted to replicate the behavior from .Net, using PowerShell, but I’ve seen it occur more often in Java-based applications.

The code connects to SQL Server and issues the following query against the AdventureWorks2019 database.

SELECT SalesOrderID, CarrierTrackingNumber, rowguid FROM Sales.SalesOrderDetail;

1	SELECT SalesOrderID, CarrierTrackingNumber, rowguid FROM Sales.SalesOrderDetail;

And then it iterates through each record, outputting the record to the console and then waiting for 1 second between each iteration.

The query itself isn’t great since, without a WHERE clause, it reads a whole table, but in SSMS it returns 121317 rows in under 1 second.

The code

#Connection parameters (yes, they're hardcoded)
$server = "LOCALHOST\VSQL2019"
$database = "AdventureWorks2019"
$login = ""
$password = ""

#Create a SQL connection
$sqlConnection = New-Object System.Data.SqlClient.SqlConnection
if (!([string]::IsNullOrEmpty($login))) {
    $connectionString = "Server=$server;Database=$database;User Id=$login;Password=$password;;"
} else {
    $connectionString = "Server=$server;Database=$database;trusted_connection=true;"
}
$sqlConnection.ConnectionString = $connectionString

# Open the connection
$sqlConnection.Open()

# Define the query
$query = "SELECT SalesOrderID, CarrierTrackingNumber, rowguid FROM Sales.SalesOrderDetail;"

# Create a SQL command
$sqlCommand = $sqlConnection.CreateCommand()
$sqlCommand.CommandText = $query

# Execute the query and process the result set
$sqlReader = $sqlCommand.ExecuteReader()

while ($sqlReader.Read()) {
    # List individual row
    $column1Value = $sqlReader["SalesOrderID"]
    $column2Value = $sqlReader["CarrierTrackingNumber"]
    $column3Value = $sqlReader["rowguid"]

    Write-Host "Sales Order ID: $column1Value, Carrier Tracking Number: $column2Value, row GUID: $column3Value"
    # wait for 1 second before going to next row
    Start-Sleep -Milliseconds 1000
}

# Close reader
$sqlReader.Close()

# Close the connection when done
$sqlConnection.Close()

#Connection parameters (yes, they're hardcoded)

$server = "LOCALHOST\VSQL2019"

$database = "AdventureWorks2019"

$login = ""

$password = ""

#Create a SQL connection

$sqlConnection = New-Object System.Data.SqlClient.SqlConnection

if (!([string]::IsNullOrEmpty($login))) {

$connectionString = "Server=$server;Database=$database;User Id=$login;Password=$password;;"

} else {

$connectionString = "Server=$server;Database=$database;trusted_connection=true;"

}

$sqlConnection.ConnectionString = $connectionString

# Open the connection

$sqlConnection.Open()

# Define the query

$query = "SELECT SalesOrderID, CarrierTrackingNumber, rowguid FROM Sales.SalesOrderDetail;"

# Create a SQL command

$sqlCommand = $sqlConnection.CreateCommand()

$sqlCommand.CommandText = $query

# Execute the query and process the result set

$sqlReader = $sqlCommand.ExecuteReader()

while ($sqlReader.Read()) {

# List individual row

$column1Value = $sqlReader["SalesOrderID"]

$column2Value = $sqlReader["CarrierTrackingNumber"]

$column3Value = $sqlReader["rowguid"]

Write-Host "Sales Order ID: $column1Value, Carrier Tracking Number: $column2Value, row GUID: $column3Value"

# wait for 1 second before going to next row

Start-Sleep -Milliseconds 1000

}

# Close reader

$sqlReader.Close()

# Close the connection when done

$sqlConnection.Close()

You can find the PowerShell script in my blog’s GitHub repository.

To run the script just update the parameter values to match your environment and then execute the script.

.\Cause_ASYNC_NETWORK_IO.ps1

1	.\Cause_ASYNC_NETWORK_IO.ps1

Diagnosing ASYNC_NETWORK_IO waits

As with every “my currently running process is slow” issue, I start by running sp_BlitzWho to get a sense of what’s actually being executed at that moment.

EXEC sp_BlitzWho;

1	EXEC sp_BlitzWho;

And I can already see that the session has been active for a little under 4 minutes at this point, the wait_info (which is the current wait) is ASYNC_NETWORK_IO with a wait time of 1428 milliseconds, and the top_session_waits also consist of 234019 milliseconds worth of ASYNC_NETWORK_IO wait time which converts to 3.9 minutes.

Note that, depending on the query complexity and/or the complexity of the queries previously executed by the session, you might have other waits besides ASYNC_NETWORK_IO in your top_session_waits field.

In this case, this is already a firm indicator that the application is behaving in such a way that causes the excessive ASYNC_NETWORK_IO waits.

To have more confirmation of this behavior, I like to run multiple executions of sp_BlitzWho at 10 second intervals to get a better sense of what’s going on.

To make things easier to read, I also output the results to a table that I can query afterwards.

EXEC sp_BlitzWho
  @OutputDatabaseName = 'DBATools',
  @OutputSchemaName   = 'dbo',
  @OutputTableName    = 'BlitzWhoOut';
WAITFOR DELAY '00:00:10';
GO 10

EXEC sp_BlitzWho

@OutputDatabaseName = 'DBATools',

@OutputSchemaName = 'dbo',

@OutputTableName = 'BlitzWhoOut';

WAITFOR DELAY '00:00:10';

GO 10

SELECT *
FROM   BlitzWhoOut;

1 2	SELECT * FROM BlitzWhoOut;

When querying the output table, there’s a noticeable pattern.

The ASYNC_NETWORK_IO wait time in the wait_info column doesn’t increase in lockstep with the one in the top_session_waits column (which increases by roughly 10 seconds every time sp_BlitzWho catures a new record) indicating that the current wait resets when the client app fetches a new batch of records from the result set.
In 10 executions of sp_BlitzWho there are no other active wait events besides ASYNC_NETWORK_IO, meaning that whatever processing SQL Server had to do to provide the results is already finished and the sole bottleneck at this point is the rate at which the client application ingests data from the output buffer.

Another way to see what’s happening on the instance currently, in terms of waits and resources, is sp_BlitzFirst.

Which also outlines the ASYNC_NETWORK_IO wait time.

EXEC sp_BlitzFirst;

1	EXEC sp_BlitzFirst;

Another gotcha with ASYNC_NETWORK_IO is that it also makes SQL Server hold locks on the object(s) being referenced by the query until the client application finishes ingesting the result set.

/*get active sessions*/
EXEC sp_BlitzWho;
/*get locks for AdventureWorks2019 
- query modified from 
 https://www.mssqltips.com/sqlservertip/1968/understanding-sql-server-locking/
*/
SELECT [lck].[resource_type],
       CASE
         WHEN [lck].[resource_type] IN ( N'DATABASE', N'FIlck.', N'METADATA' ) THEN [lck].[resource_type]
         WHEN [lck].[resource_type] = N'OBJECT' THEN OBJECT_NAME([lck].[resource_associated_entity_id], [sp].[dbid])
         WHEN [lck].[resource_type] IN ( N'KEY', N'PAGE', N'RID' ) THEN (SELECT OBJECT_NAME([object_id])
                                                                         FROM   sys.[partitions]
                                                                         WHERE  sys.[partitions].[hobt_id] = [lck].[resource_associated_entity_id])
         ELSE 'N/A'
       END         AS [locked_object_name],
       [lck].[request_mode],
       [lck].[request_status],
       [sq].[TEXT] AS [sql_text],
       [sp].[lastwaittype],
       [sp].[spid],
       [sp].[blocked],
       [sp].[status],
       [sp].[loginame],
       [sp].[program_name]
FROM   sys.[dm_tran_locks] AS [lck]
       INNER JOIN sys.[sysprocesses] AS [sp]
               ON [lck].[request_session_id] = [sp].[spid]
       CROSS APPLY sys.dm_exec_sql_text([sp].[sql_handle]) AS [sq]
WHERE  [sp].[dbid] = DB_ID('AdventureWorks2019')
       AND [lck].[resource_type] <> N'DATABASE'
ORDER  BY [lck].[request_session_id];

/*get active sessions*/

EXEC sp_BlitzWho;

/*get locks for AdventureWorks2019

- query modified from

https://www.mssqltips.com/sqlservertip/1968/understanding-sql-server-locking/

SELECT [lck].[resource_type],

CASE

WHEN [lck].[resource_type] IN ( N'DATABASE', N'FIlck.', N'METADATA' ) THEN [lck].[resource_type]

WHEN [lck].[resource_type] = N'OBJECT' THEN OBJECT_NAME([lck].[resource_associated_entity_id], [sp].[dbid])

WHEN [lck].[resource_type] IN ( N'KEY', N'PAGE', N'RID' ) THEN (SELECT OBJECT_NAME([object_id])

FROM sys.[partitions]

WHERE sys.[partitions].[hobt_id] = [lck].[resource_associated_entity_id])

ELSE 'N/A'

END AS [locked_object_name],

[lck].[request_mode],

[lck].[request_status],

[sq].[TEXT] AS [sql_text],

[sp].[lastwaittype],

[sp].[spid],

[sp].[blocked],

[sp].[status],

[sp].[loginame],

[sp].[program_name]

FROM sys.[dm_tran_locks] AS [lck]

INNER JOIN sys.[sysprocesses] AS [sp]

ON [lck].[request_session_id] = [sp].[spid]

CROSS APPLY sys.dm_exec_sql_text([sp].[sql_handle]) AS [sq]

WHERE [sp].[dbid] = DB_ID('AdventureWorks2019')

AND [lck].[resource_type] <> N'DATABASE'

ORDER BY [lck].[request_session_id];

So 46 minutes later we still have the client application chugging along through the result set, incurring 2757611 milliseconds of ASYNC_NETWORK_IO wait time, and holding shared locks on pages in the Sales.SalesOrderDetail table.

The fix

Well, here’s where any DBA can use those 3 magic words:

Fix your code

Since the issue is solely rooted in the way the application handles the result set provided by SQL Server.

If the application processes the result set just to write them back in the database after applying some business logic to the data, then move the processing and business logic in SQL Server in the form of a stored procedure.

The only thing worst then doing RBAR type processing inside SQL Server, is making SQL Server wait for you to do it outside of it only to send it back its way afterwards.

If the client application should output the records to a file (like an Excel report) then load the whole result set in memory, then apply there whatever business logic might be needed and then write them to the file.

Conclusion

SQL Server’s innocent this time.

Cookie	Duration	Description
cookielawinfo-checbox-analytics	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookie is used to store the user consent for the cookies in the category "Analytics".
cookielawinfo-checbox-functional	11 months	The cookie is set by GDPR cookie consent to record the user consent for the cookies in the category "Functional".
cookielawinfo-checbox-others	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookie is used to store the user consent for the cookies in the category "Other.
cookielawinfo-checkbox-necessary	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookies is used to store the user consent for the cookies in the category "Necessary".
cookielawinfo-checkbox-performance	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookie is used to store the user consent for the cookies in the category "Performance".
viewed_cookie_policy	11 months	The cookie is set by the GDPR Cookie Consent plugin and is used to store whether or not user has consented to the use of cookies. It does not store any personal data.