FIX: Errors when a client application sends an attention signal to SQL Server 2008 or SQL Server 2008 R2
http://support.microsoft.com/kb/2543687
This fix was specific to the following message and having to do with Attentions:
Error: 18056, Severity: 20,
State: 29.
The client was unable to reuse a session with <SPID>, which had been reset for connection pooling.
The failure ID is 29
. This error may have been caused by an earlier operation failing. Check the error logs for failed operations immediately before this error message.
Since this was released, there has still continued to be confusion over this error. The intent of the fix above was to limit the amount of noise in the ERRORLOG. And, this was specific to receiving the State 29 with 18056 when an Attention was received. The
Attention
is the important part here. If an Attention occurred during a reset of a connection, we would normally log that to the ERRORLOG under the State 29. However, with this fix applied, if the Attention occurs during the reset of a connection, you should no longer see the error within the ERRORLOG. This does NOT mean that you will no longer see a State 29.
I will use this post to explain further how we handle these errors to give you a better understanding. To do that, I will expand on Bob Dorr's blog post that I linked above which lists out the states.
Frame: Number = 175, Captured Frame Length = 116, MediaType = ETHERNET
+ Ethernet: Etype = Internet IP (IPv4),DestinationAddress:[00-15-5D-4C-B9-60],SourceAddress:[00-15-5D-4C-B9-52]
+ Ipv4: Src = 10.0.0.11, Dest = 10.0.0.130, Next Protocol = TCP, Packet ID = 18133, Total IP Length = 102
+ Tcp: [Bad CheckSum]Flags=...AP..., SrcPort=59854, DstPort=1433, PayloadLen=62, Seq=4058275796 - 4058275858, Ack=1214473613, Win=509 (scale factor 0x8) = 130304
- Tds: SQLBatch, Version = 7.3 (0x730b0003), SPID = 0, PacketID = 1, Flags=...AP..., SrcPort=59854, DstPort=1433, PayloadLen=62, Seq=4058275796 - 4058275858, Ack=1214473613, Win=130304
- PacketHeader: SPID = 0, Size = 62, PacketID = 1, Window = 0
PacketType: SQLBatch, 1(0x01)
Status: End of message true, ignore event false, reset connection true, reset connection skip tran false
Length: 62 (0x3E)
SPID: 0 (0x0)
PacketID: 1 (0x1)
Window: 0 (0x0)
- TDSSqlBatchData:
+ AllHeadersData: Head Type = MARS Header
SQLText: select @@version
In the above example, we are issuing a SQL Batch on a pooled connection. Because it was a pooled connection, we have to signal that we need to reset the connection before the Batch is executed. This is done via the "reset connection" bit.
After the above SQLBatch is issued, the app could then turn around and issue an Attention to cancel the request. This is what resulted in the 18056 with State 29 in the past under the condition of an attention.
Frame: Number = 176, Captured Frame Length = 62, MediaType = ETHERNET
+ Ethernet: Etype = Internet IP (IPv4),DestinationAddress:[00-15-5D-4C-B9-60],SourceAddress:[00-15-5D-4C-B9-52]
+ Ipv4: Src = 10.0.0.11, Dest = 10.0.0.130, Next Protocol = TCP, Packet ID = 18143, Total IP Length = 48
+ Tcp: [Bad CheckSum]Flags=...AP..., SrcPort=59854, DstPort=1433, PayloadLen=8, Seq=4058275858 - 4058275866, Ack=1214473613, Win=509 (scale factor 0x8) = 130304
- Tds: Attention, Version = 7.3 (0x730b0003), SPID = 0, PacketID = 1, Flags=...AP..., SrcPort=59854, DstPort=1433, PayloadLen=8, Seq=4058275858 - 4058275866, Ack=1214473613, Win=130304
- PacketHeader: SPID = 0, Size = 8, PacketID = 1, Window = 0
PacketType: Attention, 6(0x06)
Status: End of message true, ignore event false, reset connection false, reset connection skip tran false
Length: 8 (0x8)
SPID: 0 (0x0)
PacketID: 1 (0x1)
Window: 0 (0x0)
In this case, we would still be in the process of doing the connection reset which would be a problem. Bob Dorr's
Part 2
blog that is linked above goes into good detail for how this actually occurs.
<Record id= "3707218" type="RING_BUFFER_EXCEPTION" time="267850787"><Exception><Task address="0x52BDDC8"></Task><Error>
3617
</Error><Severity>25</Severity><State>23</State><UserDefined>0</UserDefined></Exception><Stack
There are things that occur in the course of resetting a login that could trigger a State 29. One example that we have seen is a Lock Timeout (1222).
In the Lock Timeout scenario, the only thing logged to the ERRORLOG was the 18056. We had to review the dm_os_ring_buffers DMV to see the Lock Timeout.
<Record id= "3707217" type="RING_BUFFER_EXCEPTION" time="267850784"><Exception><Task address="0x4676A42C8"></Task><Error>
1222
</Error><Severity>16</Severity><State>55</State><UserDefined>0</UserDefined></Exception><Stack
The Lock Timeout was a result of statements issuing "SET LOCK_TIMEOUT 0" which affects the connection itself. When the connection is "reset", the SET statements are carried forward. Then based on timing, and whether an exclusive lock is taken based on what the Login logic is looking for, it could end up affecting Logins off of a Pooled Connection when that connection is reused. The default lock timeout for a connection is -1.
select cast(record as XML) as recordXML
from sys.dm_os_ring_buffers
where ring_buffer_type = 'RING_BUFFER_EXCEPTION'
The error that you find should help explain the condition, and/or allow you to troubleshoot the problem further. If you see 3617, then you will want to look at applying the hotfix above to prevent those messages from being logged. If you see a different error, then you may want to collect additional data (Profiler Trace, Network Trace, etc…) to assist with determining what could have led to that error.
Adam W. Saxton | Microsoft Escalation Services
https://twitter.com/awsaxton
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.