SQL Mysteries: Why am I Still Seeing 17830 Errors?

SQL Mysteries: Why am I​​ Still Seeing 17830​​ Errors?

 

I was recently contacted by​​ Christophe Laporte​​ posing​​ a very interesting question.

 

This is about the blog post you published a while ago, but I’ have a couple a questions regarding the error which is firing an XEvent almost every 10 ms.

SQL Mysteries: Why is my SQL Server experiencing lots of 17830 (TCP 10054) errors? – SQL Server According to Bob (bobsql.com)

and

SQL Mysteries: SQL Server Login Timeouts – A Debugging Story | Microsoft Docs

 

I’ve made a bunch of simple testing on a lab environment to reproduce the issue of my customer.

And it appears that the event is​​ raised on the logout statement, but not on the login statement.

 

Repro (Powershell commands and​​ XEvent):

 

$connectionString​​ =​​ 'Data Source=ServerName;database=master;Pooling=False;Trusted_Connection=yes'

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

$sqlConnection.Open()

Start-Sleep​​ -s​​ 1​​ 

$sqlConnection.Close()​​ 

 

CREATE​​ EVENT​​ SESSION​​ [LoginIssues]​​ ON​​ SERVER​​ 

ADD​​ EVENT​​ sqlserver.connectivity_ring_buffer_recorded(

   ​​ ACTION(sqlos.task_time,sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_id,sqlserver.database_name,sqlserver.is_system,sqlserver.nt_username,sqlserver.session_id,sqlserver.session_nt_username,sqlserver.sql_text,sqlserver.username)),

ADD​​ EVENT​​ sqlserver.login(SET​​ collect_options_text=(1)

   ​​ ACTION(sqlos.task_time,sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_id,sqlserver.database_name,sqlserver.is_system,sqlserver.nt_username,sqlserver.session_id,sqlserver.session_nt_username,sqlserver.sql_text,sqlserver.username)),

ADD​​ EVENT​​ sqlserver.logout(

   ​​ ACTION(sqlos.task_time,sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_id,sqlserver.database_name,sqlserver.is_system,sqlserver.nt_username,sqlserver.session_id,sqlserver.session_nt_username,sqlserver.sql_text,sqlserver.username)),

ADD​​ EVENT​​ sqlserver.security_error_ring_buffer_recorded(

   ​​ ACTION(sqlos.task_time,sqlserver.client_app_name,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.database_id,sqlserver.database_name,sqlserver.is_system,sqlserver.nt_username,sqlserver.session_id,sqlserver.session_nt_username,sqlserver.sql_text,sqlserver.username))

ADD​​ TARGET​​ package0.ring_buffer

WITH​​ (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)

GO

 

 

Using Pooling=false forces the logout, else the event connectivity_ring_buffer_recorded with error 17830 is not raised.

 

The XEvent records the login event, and only when logout is sent by the client application, 1 second later, the event​​ connectivity_ring_buffer_recorded​​ event is fired. And then the logout.

 

 

 

I started debugging the scenario and found that if I replaced the sleep​​ command​​ with any​​ SQL​​ command execution the behavior no longer reproduced.

 

$cmd​​ =​​ $sqlConnection.CreateCommand()

$cmd.CommandText​​ =​​ "select 100";

$cmd.ExecuteScalar() 

$cmd.Dispose()

 

I then reproduced the same problem in a C# (.Net) application as well as an ODBC application. ​​ In the process of reproducing​​ the behavior​​ I stepped through the client side (SNI) code and found no difference in how the connection is being established or closed,​​ with or without the​​ command​​ execution.

 

Looking at network traces,​​ with my colleague Kapil,​​ we found the network trace was identical for the connect and disconnect​​ events,​​ with or without the command execution.

 

This led me to start looking closer at the SQL Server SNI code where I uncovered the reason for the 17830 logging and filed a work item with the connectivity team to review the behavior.

 

This issue stems from the​​ success or failure​​ of the​​ first TDS packet read after the login​​ is complete. ​​​​ 

 

The disconnect of the client​​ results in​​ a close of the socket. ​​ The​​ client socket​​ close​​ then​​ results in​​ a​​ read completion on the SQL Server indicating the connection no longer exists and SQL Server should proceed with disconnect activities.

 

The​​ SQL Server​​ disconnect code path always logs a connectivity ring buffer entry for the close. ​​​​ In this case there is an additional​​ check. ​​ If the client logged in and never sent a request the 17830 is logged indicating the first packet​​ after login​​ was never received.  ​​​​ Therefore​​ the 17830 is recorded at the point of disconnect.

 

This pattern indicates you have a client connecting to the SQL Server, never running a SQL command, and disconnecting. ​​ It is most likely an application​​ or networking/firewall​​ error,​​ but you should review the information carefully to ensure it is not an unexpected probe of the server.

 

Thanks to​​ Christophe Laporte​​ for an interesting​​ question.

  • Bob Dorr