From 884c67c2ce0a73fcb51d7a3defcb5055d44b1f9f Mon Sep 17 00:00:00 2001 From: Cheena Malhotra Date: Tue, 19 Oct 2021 15:02:38 -0700 Subject: [PATCH] Revert mars state machine changes (#1357) --- .../src/Microsoft.Data.SqlClient.csproj | 1 - .../Microsoft/Data/SqlClient/SNI/SNICommon.cs | 69 +- .../Data/SqlClient/SNI/SNIMarsConnection.cs | 590 ++++++++---------- .../Data/SqlClient/SNI/SNIMarsHandle.cs | 43 +- .../Data/SqlClient/SNI/SNINpHandle.cs | 2 +- .../Data/SqlClient/SNI/SNIPacket.Debug.cs | 187 ------ .../Microsoft/Data/SqlClient/SNI/SNIPacket.cs | 107 ++-- .../Data/SqlClient/SNI/SNIPhysicalHandle.cs | 35 +- .../Data/SqlClient/SNI/SNITcpHandle.cs | 2 +- .../Data/SqlClient/SqlClientEventSource.cs | 20 +- .../ManualTests/SQL/MARSTest/MARSTest.cs | 59 ++ 11 files changed, 443 insertions(+), 672 deletions(-) delete mode 100644 src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.Debug.cs diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft.Data.SqlClient.csproj b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft.Data.SqlClient.csproj index 86baae9553..5b808d9b78 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft.Data.SqlClient.csproj +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft.Data.SqlClient.csproj @@ -614,7 +614,6 @@ - diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNICommon.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNICommon.cs index 50d8ea239c..b57dc4f5f3 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNICommon.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNICommon.cs @@ -35,40 +35,30 @@ internal enum SNIProviders /// /// SMUX packet header /// - internal struct SNISMUXHeader + internal sealed class SNISMUXHeader { public const int HEADER_LENGTH = 16; - public byte SMID { get; private set; } - public byte Flags { get; private set; } - public ushort SessionId { get; private set; } - public uint Length { get; private set; } - public uint SequenceNumber { get; private set; } - public uint Highwater { get; private set; } - - public void Set(byte smid, byte flags, ushort sessionID, uint length, uint sequenceNumber, uint highwater) - { - SMID = smid; - Flags = flags; - SessionId = sessionID; - Length = length; - SequenceNumber = sequenceNumber; - Highwater = highwater; - } + public byte SMID; + public byte flags; + public ushort sessionId; + public uint length; + public uint sequenceNumber; + public uint highwater; public void Read(byte[] bytes) { SMID = bytes[0]; - Flags = bytes[1]; - SessionId = BitConverter.ToUInt16(bytes, 2); - Length = BitConverter.ToUInt32(bytes, 4) - SNISMUXHeader.HEADER_LENGTH; - SequenceNumber = BitConverter.ToUInt32(bytes, 8); - Highwater = BitConverter.ToUInt32(bytes, 12); + flags = bytes[1]; + sessionId = BitConverter.ToUInt16(bytes, 2); + length = BitConverter.ToUInt32(bytes, 4) - SNISMUXHeader.HEADER_LENGTH; + sequenceNumber = BitConverter.ToUInt32(bytes, 8); + highwater = BitConverter.ToUInt32(bytes, 12); } public void Write(Span bytes) { - uint value = Highwater; + uint value = highwater; // access the highest element first to cause the largest range check in the jit, then fill in the rest of the value and carry on as normal bytes[15] = (byte)((value >> 24) & 0xff); bytes[12] = (byte)(value & 0xff); // BitConverter.GetBytes(_currentHeader.highwater).CopyTo(headerBytes, 12); @@ -76,53 +66,32 @@ public void Write(Span bytes) bytes[14] = (byte)((value >> 16) & 0xff); bytes[0] = SMID; // BitConverter.GetBytes(_currentHeader.SMID).CopyTo(headerBytes, 0); - bytes[1] = Flags; // BitConverter.GetBytes(_currentHeader.flags).CopyTo(headerBytes, 1); + bytes[1] = flags; // BitConverter.GetBytes(_currentHeader.flags).CopyTo(headerBytes, 1); - value = SessionId; + value = sessionId; bytes[2] = (byte)(value & 0xff); // BitConverter.GetBytes(_currentHeader.sessionId).CopyTo(headerBytes, 2); bytes[3] = (byte)((value >> 8) & 0xff); - value = Length; + value = length; bytes[4] = (byte)(value & 0xff); // BitConverter.GetBytes(_currentHeader.length).CopyTo(headerBytes, 4); bytes[5] = (byte)((value >> 8) & 0xff); bytes[6] = (byte)((value >> 16) & 0xff); bytes[7] = (byte)((value >> 24) & 0xff); - value = SequenceNumber; + value = sequenceNumber; bytes[8] = (byte)(value & 0xff); // BitConverter.GetBytes(_currentHeader.sequenceNumber).CopyTo(headerBytes, 8); bytes[9] = (byte)((value >> 8) & 0xff); bytes[10] = (byte)((value >> 16) & 0xff); bytes[11] = (byte)((value >> 24) & 0xff); } - - public SNISMUXHeader Clone() - { - SNISMUXHeader copy = new SNISMUXHeader(); - copy.SMID = SMID; - copy.Flags = Flags; - copy.SessionId = SessionId; - copy.Length = Length; - copy.SequenceNumber = SequenceNumber; - copy.Highwater = Highwater; - return copy; - } - - public void Clear() - { - SMID = 0; - Flags = 0; - SessionId = 0; - Length = 0; - SequenceNumber = 0; - Highwater = 0; - } } /// /// SMUX packet flags /// - internal enum SNISMUXFlags : uint + [Flags] + internal enum SNISMUXFlags { SMUX_SYN = 1, // Begin SMUX connection SMUX_ACK = 2, // Acknowledge SMUX packets diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsConnection.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsConnection.cs index 22e0c6eab9..395cfed4be 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsConnection.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsConnection.cs @@ -14,47 +14,50 @@ namespace Microsoft.Data.SqlClient.SNI /// internal class SNIMarsConnection { - private readonly object _sync; - private readonly Guid _connectionId; - private readonly Dictionary _sessions; + private const string s_className = nameof(SNIMarsConnection); + + private readonly Guid _connectionId = Guid.NewGuid(); + private readonly Dictionary _sessions = new Dictionary(); + private readonly byte[] _headerBytes = new byte[SNISMUXHeader.HEADER_LENGTH]; + private readonly SNISMUXHeader _currentHeader = new SNISMUXHeader(); private SNIHandle _lowerHandle; - private ushort _nextSessionId; + private ushort _nextSessionId = 0; + private int _currentHeaderByteCount = 0; + private int _dataBytesLeft = 0; + private SNIPacket _currentPacket; /// /// Connection ID /// - public Guid ConnectionId => _connectionId; + public Guid ConnectionId + { + get + { + return _connectionId; + } + } public int ProtocolVersion => _lowerHandle.ProtocolVersion; - public object DemuxerSync => _sync; - /// /// Constructor /// /// Lower handle public SNIMarsConnection(SNIHandle lowerHandle) { - _sync = new object(); - _connectionId = Guid.NewGuid(); - _sessions = new Dictionary(); - _demuxState = DemuxState.Header; - _headerCount = 0; - _headerBytes = new byte[SNISMUXHeader.HEADER_LENGTH]; - _nextSessionId = 0; _lowerHandle = lowerHandle; - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "Created MARS Session Id {0}", args0: ConnectionId); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "Created MARS Session Id {0}", args0: ConnectionId); _lowerHandle.SetAsyncCallbacks(HandleReceiveComplete, HandleSendComplete); } public SNIMarsHandle CreateMarsSession(object callbackObject, bool async) { - lock (DemuxerSync) + lock (this) { ushort sessionId = _nextSessionId++; SNIMarsHandle handle = new SNIMarsHandle(this, sessionId, callbackObject, async); _sessions.Add(sessionId, handle); - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, SNI MARS Handle Id {1}, created new MARS Session {2}", args0: ConnectionId, args1: handle?.ConnectionId, args2: sessionId); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, SNI MARS Handle Id {1}, created new MARS Session {2}", args0: ConnectionId, args1: handle?.ConnectionId, args2: sessionId); return handle; } } @@ -65,18 +68,23 @@ public SNIMarsHandle CreateMarsSession(object callbackObject, bool async) /// public uint StartReceive() { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { SNIPacket packet = null; if (ReceiveAsync(ref packet) == TdsEnums.SNI_SUCCESS_IO_PENDING) { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, Success IO pending.", args0: ConnectionId); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Success IO pending.", args0: ConnectionId); return TdsEnums.SNI_SUCCESS_IO_PENDING; } - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Connection not usable.", args0: ConnectionId); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Connection not usable.", args0: ConnectionId); return SNICommon.ReportSNIError(SNIProviders.SMUX_PROV, 0, SNICommon.ConnNotUsableError, Strings.SNI_ERROR_19); } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } } /// @@ -86,13 +94,18 @@ public uint StartReceive() /// SNI error code public uint Send(SNIPacket packet) { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { - lock (DemuxerSync) + lock (this) { return _lowerHandle.Send(packet); } } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } } /// @@ -103,13 +116,18 @@ public uint Send(SNIPacket packet) /// SNI error code public uint SendAsync(SNIPacket packet, SNIAsyncCallback callback) { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { - lock (DemuxerSync) + lock (this) { return _lowerHandle.SendAsync(packet, callback); } } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } } /// @@ -119,26 +137,31 @@ public uint SendAsync(SNIPacket packet, SNIAsyncCallback callback) /// SNI error code public uint ReceiveAsync(ref SNIPacket packet) { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { if (packet != null) { ReturnPacket(packet); #if DEBUG - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, Packet {1} returned", args0: ConnectionId, args1: packet?._id); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Packet {1} returned", args0: ConnectionId, args1: packet?._id); #endif packet = null; } - lock (DemuxerSync) + lock (this) { var response = _lowerHandle.ReceiveAsync(ref packet); #if DEBUG - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, Received new packet {1}", args0: ConnectionId, args1: packet?._id); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Received new packet {1}", args0: ConnectionId, args1: packet?._id); #endif return response; } } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } } /// @@ -147,13 +170,18 @@ public uint ReceiveAsync(ref SNIPacket packet) /// SNI error status public uint CheckConnection() { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { - lock (DemuxerSync) + lock (this) { return _lowerHandle.CheckConnection(); } } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } } /// @@ -161,22 +189,18 @@ public uint CheckConnection() /// public void HandleReceiveError(SNIPacket packet) { - Debug.Assert(Monitor.IsEntered(DemuxerSync), "HandleReceiveError was called without demuxer lock being taken."); - if (!Monitor.IsEntered(DemuxerSync)) - { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, function was called without being locked.", args0: ConnectionId); - } + Debug.Assert(Monitor.IsEntered(this), "HandleReceiveError was called without being locked."); foreach (SNIMarsHandle handle in _sessions.Values) { if (packet.HasCompletionCallback) { handle.HandleReceiveError(packet); #if DEBUG - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Packet {1} has Completion Callback", args0: ConnectionId, args1: packet?._id); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Packet {1} has Completion Callback", args0: ConnectionId, args1: packet?._id); } else { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Packet {1} does not have Completion Callback, error not handled.", args0: ConnectionId, args1: packet?._id); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Packet {1} does not have Completion Callback, error not handled.", args0: ConnectionId, args1: packet?._id); #endif } } @@ -194,15 +218,185 @@ public void HandleSendComplete(SNIPacket packet, uint sniErrorCode) packet.InvokeCompletionCallback(sniErrorCode); } + /// + /// Process a receive completion + /// + /// SNI packet + /// SNI error code + public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) + { + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try + { + SNISMUXHeader currentHeader = null; + SNIPacket currentPacket = null; + SNIMarsHandle currentSession = null; + + if (sniErrorCode != TdsEnums.SNI_SUCCESS) + { + lock (this) + { + HandleReceiveError(packet); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); + return; + } + } + + while (true) + { + lock (this) + { + if (_currentHeaderByteCount != SNISMUXHeader.HEADER_LENGTH) + { + currentHeader = null; + currentPacket = null; + currentSession = null; + + while (_currentHeaderByteCount != SNISMUXHeader.HEADER_LENGTH) + { + int bytesTaken = packet.TakeData(_headerBytes, _currentHeaderByteCount, SNISMUXHeader.HEADER_LENGTH - _currentHeaderByteCount); + _currentHeaderByteCount += bytesTaken; + + if (bytesTaken == 0) + { + sniErrorCode = ReceiveAsync(ref packet); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Non-SMUX Header SNI Packet received with code {1}", args0: ConnectionId, args1: sniErrorCode); + + if (sniErrorCode == TdsEnums.SNI_SUCCESS_IO_PENDING) + { + return; + } + + HandleReceiveError(packet); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); + return; + } + } + + _currentHeader.Read(_headerBytes); + _dataBytesLeft = (int)_currentHeader.length; + _currentPacket = _lowerHandle.RentPacket(headerSize: 0, dataSize: (int)_currentHeader.length); +#if DEBUG + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, _dataBytesLeft {1}, _currentPacket {2}, Reading data of length: _currentHeader.length {3}", args0: _lowerHandle?.ConnectionId, args1: _dataBytesLeft, args2: currentPacket?._id, args3: _currentHeader?.length); +#endif + } + + currentHeader = _currentHeader; + currentPacket = _currentPacket; + + if (_currentHeader.flags == (byte)SNISMUXFlags.SMUX_DATA) + { + if (_dataBytesLeft > 0) + { + int length = packet.TakeData(_currentPacket, _dataBytesLeft); + _dataBytesLeft -= length; + + if (_dataBytesLeft > 0) + { + sniErrorCode = ReceiveAsync(ref packet); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, SMUX DATA Header SNI Packet received with code {1}, _dataBytesLeft {2}", args0: ConnectionId, args1: sniErrorCode, args2: _dataBytesLeft); + + if (sniErrorCode == TdsEnums.SNI_SUCCESS_IO_PENDING) + { + return; + } + + HandleReceiveError(packet); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); + return; + } + } + } + + _currentHeaderByteCount = 0; + + if (!_sessions.ContainsKey(_currentHeader.sessionId)) + { + SNILoadHandle.SingletonInstance.LastError = new SNIError(SNIProviders.SMUX_PROV, 0, SNICommon.InvalidParameterError, Strings.SNI_ERROR_5); + HandleReceiveError(packet); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "Current Header Session Id {0} not found, MARS Session Id {1} will be destroyed, New SNI error created: {2}", args0: _currentHeader?.sessionId, args1: _lowerHandle?.ConnectionId, args2: sniErrorCode); + _lowerHandle.Dispose(); + _lowerHandle = null; + return; + } + + if (_currentHeader.flags == (byte)SNISMUXFlags.SMUX_FIN) + { + _sessions.Remove(_currentHeader.sessionId); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "SMUX_FIN | MARS Session Id {0}, SMUX_FIN flag received, Current Header Session Id {1} removed", args0: _lowerHandle?.ConnectionId, args1: _currentHeader?.sessionId); + } + else + { + currentSession = _sessions[_currentHeader.sessionId]; + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Current Session assigned to Session Id {1}", args0: _lowerHandle?.ConnectionId, args1: _currentHeader?.sessionId); + } + } + + if (currentHeader.flags == (byte)SNISMUXFlags.SMUX_DATA) + { + currentSession.HandleReceiveComplete(currentPacket, currentHeader); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "SMUX_DATA | MARS Session Id {0}, Current Session {1} completed receiving Data", args0: _lowerHandle?.ConnectionId, args1: _currentHeader?.sessionId); + } + + if (_currentHeader.flags == (byte)SNISMUXFlags.SMUX_ACK) + { + try + { + currentSession.HandleAck(currentHeader.highwater); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "SMUX_ACK | MARS Session Id {0}, Current Session {1} handled ack", args0: _lowerHandle?.ConnectionId, args1: _currentHeader?.sessionId); + } + catch (Exception e) + { + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "SMUX_ACK | MARS Session Id {0}, Exception occurred: {2}", args0: _currentHeader?.sessionId, args1: e?.Message); + SNICommon.ReportSNIError(SNIProviders.SMUX_PROV, SNICommon.InternalExceptionError, e); + } +#if DEBUG + Debug.Assert(_currentPacket == currentPacket, "current and _current are not the same"); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "SMUX_ACK | MARS Session Id {0}, Current Packet {1} returned", args0: _lowerHandle?.ConnectionId, args1: currentPacket?._id); +#endif + ReturnPacket(currentPacket); + currentPacket = null; + _currentPacket = null; + } + + lock (this) + { + if (packet.DataLeft == 0) + { + sniErrorCode = ReceiveAsync(ref packet); + + if (sniErrorCode == TdsEnums.SNI_SUCCESS_IO_PENDING) + { + return; + } + + HandleReceiveError(packet); + SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, packet.DataLeft 0, SNI error {2}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); + return; + } + } + } + } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } + } + /// /// Enable SSL /// public uint EnableSsl(uint options) { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { return _lowerHandle.EnableSsl(options); } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } } /// @@ -210,15 +404,26 @@ public uint EnableSsl(uint options) /// public void DisableSsl() { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { _lowerHandle.DisableSsl(); } + finally + { + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); + } } - public SNIPacket RentPacket(int headerSize, int dataSize) => _lowerHandle.RentPacket(headerSize, dataSize); + public SNIPacket RentPacket(int headerSize, int dataSize) + { + return _lowerHandle.RentPacket(headerSize, dataSize); + } - public void ReturnPacket(SNIPacket packet) => _lowerHandle.ReturnPacket(packet); + public void ReturnPacket(SNIPacket packet) + { + _lowerHandle.ReturnPacket(packet); + } #if DEBUG /// @@ -226,309 +431,16 @@ public void DisableSsl() /// public void KillConnection() { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); + try { _lowerHandle.KillConnection(); } - } -#endif - - private enum DemuxState : uint - { - Header = 1, - Payload = 2, - Dispatch = 3 - } - - private enum State : uint - { - Demux, - HandleAck, - HandleData, - Receive, - Finish, - Error - } - - - // the following variables are used only inside HandleRecieveComplete - // all access to these variables must be performed under lock(DemuxerSync) because - // RecieveAsync can immediately return a new packet causing reentrant behaviour - // without the lock. - private DemuxState _demuxState; - - private byte[] _headerBytes; - private int _headerCount; - private SNISMUXHeader _header; - - private int _payloadLength; - private int _payloadCount; - - private SNIPacket _partial; - - public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) - { - using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + finally { - if (sniErrorCode != TdsEnums.SNI_SUCCESS) - { - lock (DemuxerSync) - { - HandleReceiveError(packet); - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); - return; - } - } - - State state = State.Demux; - State nextState = State.Demux; - - SNISMUXHeader handleHeader = default; - SNIMarsHandle handleSession = null; - SNIPacket handlePacket = null; - - while (state != State.Error && state != State.Finish) - { - switch (state) - { - case State.Demux: - lock (DemuxerSync) - { - switch (_demuxState) - { - case DemuxState.Header: - int taken = packet.TakeData(_headerBytes, _headerCount, SNISMUXHeader.HEADER_LENGTH - _headerCount); - _headerCount += taken; - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, took {1} header bytes", args0: _lowerHandle?.ConnectionId, args1: packet.DataLeft, args2: taken); - if (_headerCount == SNISMUXHeader.HEADER_LENGTH) - { - _header.Read(_headerBytes); - _payloadLength = (int)_header.Length; - _payloadCount = 0; - _demuxState = DemuxState.Payload; - state = State.Demux; - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, header complete, _payloadLength {1}", args0: _lowerHandle?.ConnectionId, args1: _payloadLength); - goto case DemuxState.Payload; - } - else - { - state = State.Receive; - } - break; - - case DemuxState.Payload: - if (packet.DataLeft == _payloadLength && _partial == null) - { - // if the data in the packet being processed is exactly and only the data that is going to sent - // on to the parser then don't copy it to a new packet just forward the current packet once we've - // fiddled the data pointer so that it skips the header data - _partial = packet; - packet = null; - _partial.SetDataToRemainingContents(); - _demuxState = DemuxState.Dispatch; - state = State.Demux; - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, forwarding packet contents", args0: _lowerHandle?.ConnectionId, args1: _header.SessionId); - goto case DemuxState.Dispatch; - } - else - { - if (_partial == null) - { - _partial = RentPacket(headerSize: 0, dataSize: _payloadLength); - } - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, reconstructing packet contents", args0: _lowerHandle?.ConnectionId, args1: _header.SessionId); - int wanted = _payloadLength - _payloadCount; - int transferred = SNIPacket.TransferData(packet, _partial, wanted); - _payloadCount += transferred; - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, took {1} payload bytes", args0: _lowerHandle?.ConnectionId, args1: transferred); - - if (_payloadCount == _payloadLength) - { - // payload is complete so dispatch the current packet - _demuxState = DemuxState.Dispatch; - state = State.Receive; - goto case DemuxState.Dispatch; - } - else if (packet.DataLeft == 0) - { - // no more data in the delivered packet so wait for a new one - _demuxState = DemuxState.Payload; - state = State.Receive; - } - else - { - // data left in the delivered packet so start the demux loop - // again and decode the next packet in the input - _headerCount = 0; - _demuxState = DemuxState.Header; - state = State.Demux; - } - } - - break; - - case DemuxState.Dispatch: - if (_sessions.TryGetValue(_header.SessionId, out SNIMarsHandle session)) - { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, Current Session assigned to Session Id {1}", args0: _lowerHandle?.ConnectionId, args1: _header.SessionId); - switch ((SNISMUXFlags)_header.Flags) - { - case SNISMUXFlags.SMUX_DATA: - handleSession = session; - session = null; - handleHeader = _header.Clone(); - handlePacket = _partial; - _partial = null; - // move to the state for sending the data to the mars handle and setup - // the state that should be moved to after that operation has succeeded - state = State.HandleData; - if (packet != null && packet.DataLeft > 0) - { - nextState = State.Demux; - } - else - { - nextState = State.Receive; - } - break; - - case SNISMUXFlags.SMUX_ACK: - handleSession = session; - session = null; - handleHeader = _header.Clone(); - ReturnPacket(_partial); - _partial = null; - // move to the state for sending the data to the mars handle and setup - // the state that should be moved to after that operation has succeeded - state = State.HandleAck; - if (packet != null && packet.DataLeft > 0) - { - nextState = State.Demux; - } - else - { - nextState = State.Receive; - } - break; - - case SNISMUXFlags.SMUX_FIN: - ReturnPacket(_partial); - _partial = null; - _sessions.Remove(_header.SessionId); - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "SMUX_FIN | MARS Session Id {0}, SMUX_FIN flag received, Current Header Session Id {1} removed", args0: _lowerHandle?.ConnectionId, args1: _header.SessionId); - break; - - default: - Debug.Fail("unknown smux packet flag"); - break; - } - - // a full packet has been decoded and queued for sending by setting the state or the - // handle it was sent to no longer exists and the handle has been dropped. Now reset the - // demuxer state ready to recode another packet - _header.Clear(); - _headerCount = 0; - _demuxState = DemuxState.Header; - - // if the state is set to demux more data and there is no data left then change - // the state to request more data - if (state == State.Demux && (packet == null || packet.DataLeft == 0)) - { - if (packet != null) - { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, run out of data , queuing receive", args0: _lowerHandle?.ConnectionId, args1: _header.SessionId); - } - state = State.Receive; - } - - } - else - { - SNILoadHandle.SingletonInstance.LastError = new SNIError(SNIProviders.SMUX_PROV, 0, SNICommon.InvalidParameterError, string.Empty); - HandleReceiveError(packet); - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "Current Header Session Id {0} not found, MARS Session Id {1} will be destroyed, New SNI error created: {2}", args0: _header.SessionId, args1: _lowerHandle?.ConnectionId, args2: sniErrorCode); - packet = null; - _lowerHandle.Dispose(); - _lowerHandle = null; - state = State.Error; - } - break; - } - } - break; - - case State.HandleAck: - Debug.Assert(handleSession != null, "dispatching ack to null SNIMarsHandle"); - Debug.Assert(!Monitor.IsEntered(DemuxerSync), "do not dispatch ack to session handle while holding the demuxer lock"); - try - { - handleSession.HandleAck(handleHeader.Highwater); - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "SMUX_ACK | MARS Session Id {0}, Current Session {1} handled ack", args0: _lowerHandle?.ConnectionId, args1: _header.SessionId); - } - catch (Exception e) - { - SNICommon.ReportSNIError(SNIProviders.SMUX_PROV, SNICommon.InternalExceptionError, e); - } - finally - { - handleHeader = default; - handleSession = null; - } - state = nextState; - nextState = State.Finish; - break; - - case State.HandleData: - Debug.Assert(handleSession != null, "dispatching data to null SNIMarsHandle"); - Debug.Assert(handlePacket != null, "dispatching null data to SNIMarsHandle"); - Debug.Assert(!Monitor.IsEntered(DemuxerSync), "do not dispatch data to session handle while holding the demuxer lock"); - // do not ReturnPacket(handlePacket) the receiver is responsible for returning the packet - // once it has been used because it can take sync and async paths from to the receiver and - // only the reciever can make the decision on when it is completed and can be returned - try - { - handleSession.HandleReceiveComplete(handlePacket, handleHeader); - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "SMUX_DATA | MARS Session Id {0}, Current Session {1} completed receiving Data", args0: _lowerHandle?.ConnectionId, args1: _header.SessionId); - } - finally - { - handleHeader = default; - handleSession = null; - handlePacket = null; - } - state = nextState; - nextState = State.Finish; - break; - - case State.Receive: - if (packet != null) - { - Debug.Assert(packet.DataLeft == 0, "loop exit with data remaining"); - ReturnPacket(packet); - packet = null; - } - - lock (DemuxerSync) - { - uint receiveResult = ReceiveAsync(ref packet); - if (receiveResult == TdsEnums.SNI_SUCCESS_IO_PENDING) - { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, SMUX DATA Header SNI Packet received with code {1}", args0: ConnectionId, args1: receiveResult); - packet = null; - } - else - { - HandleReceiveError(packet); - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: receiveResult); - } - } - state = State.Finish; - break; - } - } - + SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); } } - +#endif } } diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsHandle.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsHandle.cs index 798624e594..62eff5accc 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsHandle.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIMarsHandle.cs @@ -25,7 +25,7 @@ internal sealed class SNIMarsHandle : SNIHandle private readonly ushort _sessionId; private readonly ManualResetEventSlim _packetEvent = new ManualResetEventSlim(false); private readonly ManualResetEventSlim _ackEvent = new ManualResetEventSlim(false); - //private readonly SNISMUXHeader _currentHeader = new SNISMUXHeader(); + private readonly SNISMUXHeader _currentHeader = new SNISMUXHeader(); private readonly SNIAsyncCallback _handleSendCompleteCallback; private uint _sendHighwater = 4; @@ -54,8 +54,6 @@ internal sealed class SNIMarsHandle : SNIHandle /// public override void Dispose() { - // SendControlPacket will lock so make sure that it cannot deadlock by failing to enter the DemuxerLock - Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); using (TrySNIEventScope.Create(nameof(SNIMarsHandle))) { try @@ -104,8 +102,8 @@ private void SendControlPacket(SNISMUXFlags flags) #endif lock (this) { - SNISMUXHeader header = SetupSMUXHeader(0, flags); - header.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); + SetupSMUXHeader(0, flags); + _currentHeader.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); packet.SetHeaderActive(); } @@ -118,22 +116,17 @@ private void SendControlPacket(SNISMUXFlags flags) } } - private SNISMUXHeader SetupSMUXHeader(int length, SNISMUXFlags flags) + private void SetupSMUXHeader(int length, SNISMUXFlags flags) { Debug.Assert(Monitor.IsEntered(this), "must take lock on self before updating smux header"); - SNISMUXHeader header = new SNISMUXHeader(); - header.Set( - smid: 83, - flags: (byte)flags, - sessionID: _sessionId, - length: (uint)SNISMUXHeader.HEADER_LENGTH + (uint)length, - sequenceNumber: ((flags == SNISMUXFlags.SMUX_FIN) || (flags == SNISMUXFlags.SMUX_ACK)) ? _sequenceNumber - 1 : _sequenceNumber++, - highwater: _receiveHighwater - ); - _receiveHighwaterLastAck = header.Highwater; - - return header; + _currentHeader.SMID = 83; + _currentHeader.flags = (byte)flags; + _currentHeader.sessionId = _sessionId; + _currentHeader.length = (uint)SNISMUXHeader.HEADER_LENGTH + (uint)length; + _currentHeader.sequenceNumber = ((flags == SNISMUXFlags.SMUX_FIN) || (flags == SNISMUXFlags.SMUX_ACK)) ? _sequenceNumber - 1 : _sequenceNumber++; + _currentHeader.highwater = _receiveHighwater; + _receiveHighwaterLastAck = _currentHeader.highwater; } /// @@ -144,10 +137,9 @@ private SNISMUXHeader SetupSMUXHeader(int length, SNISMUXFlags flags) private SNIPacket SetPacketSMUXHeader(SNIPacket packet) { Debug.Assert(packet.ReservedHeaderSize == SNISMUXHeader.HEADER_LENGTH, "mars handle attempting to smux packet without smux reservation"); - Debug.Assert(Monitor.IsEntered(this), "cannot create mux header outside lock"); - SNISMUXHeader header = SetupSMUXHeader(packet.DataLength, SNISMUXFlags.SMUX_DATA); - header.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); + SetupSMUXHeader(packet.Length, SNISMUXFlags.SMUX_DATA); + _currentHeader.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); packet.SetHeaderActive(); #if DEBUG SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsHandle), EventType.INFO, "MARS Session Id {0}, Setting SMUX_DATA header in current header for packet {1}", args0: ConnectionId, args1: packet?._id); @@ -276,7 +268,6 @@ private uint SendPendingPackets() /// SNI error code public override uint SendAsync(SNIPacket packet, SNIAsyncCallback callback = null) { - Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); using (TrySNIEventScope.Create(nameof(SNIMarsHandle))) { lock (this) @@ -390,7 +381,6 @@ public void HandleSendComplete(SNIPacket packet, uint sniErrorCode) /// Send highwater mark public void HandleAck(uint highwater) { - Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); using (TrySNIEventScope.Create(nameof(SNIMarsHandle))) { lock (this) @@ -412,15 +402,14 @@ public void HandleAck(uint highwater) /// SMUX header public void HandleReceiveComplete(SNIPacket packet, SNISMUXHeader header) { - Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); using (TrySNIEventScope.Create(nameof(SNIMarsHandle))) { lock (this) { - if (_sendHighwater != header.Highwater) + if (_sendHighwater != header.highwater) { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsHandle), EventType.INFO, "MARS Session Id {0}, header.highwater {1}, _sendHighwater {2}, Handle Ack with header.highwater", args0: ConnectionId, args1: header.Highwater, args2: _sendHighwater); - HandleAck(header.Highwater); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsHandle), EventType.INFO, "MARS Session Id {0}, header.highwater {1}, _sendHighwater {2}, Handle Ack with header.highwater", args0: ConnectionId, args1: header?.highwater, args2: _sendHighwater); + HandleAck(header.highwater); } lock (_receivedPacketQueue) diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNINpHandle.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNINpHandle.cs index 52c1e53baa..2b93f4e752 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNINpHandle.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNINpHandle.cs @@ -176,7 +176,7 @@ public override uint Receive(out SNIPacket packet, int timeout) packet.ReadFromStream(_stream); SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNINpHandle), EventType.INFO, "Connection Id {0}, Rented and read packet, dataLeft {1}", args0: _connectionId, args1: packet?.DataLeft); - if (packet.DataLength == 0) + if (packet.Length == 0) { errorPacket = packet; packet = null; diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.Debug.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.Debug.cs deleted file mode 100644 index 904940f19e..0000000000 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.Debug.cs +++ /dev/null @@ -1,187 +0,0 @@ -// Licensed to the .NET Foundation under one or more agreements. -// The .NET Foundation licenses this file to you under the MIT license. -// See the LICENSE file in the project root for more information. - -//#define TRACE_HISTORY // this is used for advanced debugging when you need to trace where a packet is rented and returned, mostly used to identify double - // return problems - -//#define TRACE_PATH // this is used for advanced debugging when you need to see what functions the packet passes through. In each location you want to trace - // add a call to PushPath or PushPathStack e.g. packet.PushPath(new StackTrace().ToString()); and then when you hit a breakpoint or - // assertion failure inspect the _path variable to see the pushed entries since the packet was rented. - -using System; -using System.Collections.Generic; -using System.Diagnostics; -using System.Linq; - -namespace Microsoft.Data.SqlClient.SNI -{ -#if DEBUG - internal sealed partial class SNIPacket - { -#if TRACE_HISTORY - [DebuggerDisplay("{Action.ToString(),nq}")] - internal struct History - { - public enum Direction - { - Rent = 0, - Return = 1, - } - - public Direction Action; - public int RefCount; - public string Stack; - } -#endif - -#if TRACE_PATH - [DebuggerTypeProxy(typeof(PathEntryDebugView))] - [DebuggerDisplay("{Name,nq}")] - internal sealed class PathEntry - { - public PathEntry Previous = null; - public string Name = null; - } - - internal sealed class PathEntryDebugView - { - private readonly PathEntry _data; - - public PathEntryDebugView(PathEntry data) - { - if (data == null) - { - throw new ArgumentNullException(nameof(data)); - } - - _data = data; - } - - [DebuggerBrowsable(DebuggerBrowsableState.RootHidden)] - public string[] Items - { - get - { - string[] items = Array.Empty(); - if (_data != null) - { - int count = 0; - for (PathEntry current = _data; current != null; current = current?.Previous) - { - count++; - } - items = new string[count]; - int index = 0; - for (PathEntry current = _data; current != null; current = current?.Previous, index++) - { - items[index] = current.Name; - } - } - return items; - } - } - } -#endif - - internal readonly int _id; // in debug mode every packet is assigned a unique id so that the entire lifetime can be tracked when debugging - /// refcount = 0 means that a packet should only exist in the pool - /// refcount = 1 means that a packet is active - /// refcount > 1 means that a packet has been reused in some way and is a serious error - internal int _refCount; - internal readonly SNIHandle _owner; // used in debug builds to check that packets are being returned to the correct pool - internal string _traceTag; // used to assist tracing what steps the packet has been through -#if TRACE_PATH - internal PathEntry _path; -#endif -#if TRACE_HISTORY - internal List _history; -#endif - - public void PushPath(string name) - { -#if TRACE_PATH - var entry = new PathEntry { Previous = _path, Name = name }; - _path = entry; -#endif - } - - public void PushPathStack() - { -#if TRACE_PATH - PushPath(new StackTrace().ToString()); -#endif - } - - public void PopPath() - { -#if TRACE_PATH - _path = _path?.Previous; -#endif - } - - public void ClearPath() - { -#if TRACE_PATH - _path = null; -#endif - } - - public void AddHistory(bool renting) - { -#if TRACE_HISTORY - _history.Add( - new History - { - Action = renting ? History.Direction.Rent : History.Direction.Return, - Stack = GetStackParts(), - RefCount = _refCount - } - ); -#endif - } - - /// - /// uses the packet refcount in debug mode to identify if the packet is considered active - /// it is an error to use a packet which is not active in any function outside the pool implementation - /// - public bool IsActive => _refCount == 1; - - public SNIPacket(SNIHandle owner, int id) - : this() - { - _id = id; - _owner = owner; -#if TRACE_PATH - _path = null; -#endif -#if TRACE_HISTORY - _history = new List(); -#endif - } - - // the finalizer is only included in debug builds and is used to ensure that all packets are correctly recycled - // it is not an error if a packet is dropped but it is undesirable so all efforts should be made to make sure we - // do not drop them for the GC to pick up - ~SNIPacket() - { - if (_data != null) - { - Debug.Fail($@"finalizer called for unreleased SNIPacket, tag: {_traceTag}"); - } - } - -#if TRACE_HISTORY - private string GetStackParts() - { - return string.Join(Environment.NewLine, - Environment.StackTrace - .Split(new string[] { Environment.NewLine }, StringSplitOptions.None) - .Skip(3) // trims off the common parts at the top of the stack so you can see what the actual caller was - .Take(9) // trims off most of the bottom of the stack because when running under xunit there's a lot of spam - ); - } -#endif - } -#endif -} diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.cs index 99725577bb..58ac68c7c4 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.cs @@ -2,8 +2,11 @@ // The .NET Foundation licenses this file to you under the MIT license. // See the LICENSE file in the project root for more information. + // #define TRACE_HISTORY // this is used for advanced debugging when you need to trace the entire lifetime of a single packet, be very careful with it + using System; using System.Buffers; +using System.Collections.Generic; using System.Diagnostics; using System.IO; using System.Threading; @@ -14,7 +17,7 @@ namespace Microsoft.Data.SqlClient.SNI /// /// SNI Packet /// - internal sealed partial class SNIPacket + internal sealed class SNIPacket { private int _dataLength; // the length of the data in the data segment, advanced by Append-ing data, does not include smux header length private int _dataCapacity; // the total capacity requested, if the array is rented this may be less than the _data.Length, does not include smux header length @@ -24,7 +27,62 @@ internal sealed partial class SNIPacket private byte[] _data; private SNIAsyncCallback _completionCallback; private readonly Action, object> _readCallback; +#if DEBUG + internal readonly int _id; // in debug mode every packet is assigned a unique id so that the entire lifetime can be tracked when debugging + /// refcount = 0 means that a packet should only exist in the pool + /// refcount = 1 means that a packet is active + /// refcount > 1 means that a packet has been reused in some way and is a serious error + internal int _refCount; + internal readonly SNIHandle _owner; // used in debug builds to check that packets are being returned to the correct pool + internal string _traceTag; // used in debug builds to assist tracing what steps the packet has been through + +#if TRACE_HISTORY + [DebuggerDisplay("{Action.ToString(),nq}")] + internal struct History + { + public enum Direction + { + Rent = 0, + Return = 1, + } + + public Direction Action; + public int RefCount; + public string Stack; + } + + internal List _history = null; +#endif + + /// + /// uses the packet refcount in debug mode to identify if the packet is considered active + /// it is an error to use a packet which is not active in any function outside the pool implementation + /// + public bool IsActive => _refCount == 1; + + public SNIPacket(SNIHandle owner, int id) + : this() + { +#if TRACE_HISTORY + _history = new List(); +#endif + _id = id; + _owner = owner; + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIPacket), EventType.INFO, "Connection Id {0}, Packet Id {1} instantiated,", args0: _owner?.ConnectionId, args1: _id); + } + // the finalizer is only included in debug builds and is used to ensure that all packets are correctly recycled + // it is not an error if a packet is dropped but it is undesirable so all efforts should be made to make sure we + // do not drop them for the GC to pick up + ~SNIPacket() + { + if (_data != null) + { + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIPacket), EventType.ERR, "Finalizer called for unreleased SNIPacket, Connection Id {0}, Packet Id {1}, _refCount {2}, DataLeft {3}, tag {4}", args0: _owner?.ConnectionId, args1: _id, args2: _refCount, args3: DataLeft, args4: _traceTag); + } + } + +#endif public SNIPacket() { _readCallback = ReadFromStreamAsyncContinuation; @@ -33,7 +91,7 @@ public SNIPacket() /// /// Length of data left to process /// - public int DataLeft => _dataLength - _dataOffset; + public int DataLeft => (_dataLength - _dataOffset); /// /// Indicates that the packet should be sent out of band bypassing the normal send-recieve lock @@ -43,7 +101,7 @@ public SNIPacket() /// /// Length of data /// - public int DataLength => _dataLength; + public int Length => _dataLength; /// /// Packet validity @@ -96,8 +154,7 @@ public void Allocate(int headerLength, int dataLength) /// Number of bytes read from the packet into the buffer public void GetData(byte[] buffer, ref int dataSize) { - Debug.Assert(_data != null, "GetData on empty or returned packet"); - Buffer.BlockCopy(_data, _headerLength + _dataOffset, buffer, 0, _dataLength); + Buffer.BlockCopy(_data, _headerLength, buffer, 0, _dataLength); dataSize = _dataLength; } @@ -109,9 +166,7 @@ public void GetData(byte[] buffer, ref int dataSize) /// Amount of data taken public int TakeData(SNIPacket packet, int size) { - Debug.Assert(_data != null, "TakeData on empty or returned packet"); - int dataSize = TakeData(packet._data, packet._headerLength + packet._dataOffset, size); - Debug.Assert(packet._dataLength + dataSize <= packet._dataCapacity, "added too much data to a packet"); + int dataSize = TakeData(packet._data, packet._headerLength + packet._dataLength, size); packet._dataLength += dataSize; #if DEBUG SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIPacket), EventType.INFO, "Connection Id {0}, Packet Id {1} took data from Packet Id {2} dataSize {3}, _dataLength {4}", args0: _owner?.ConnectionId, args1: _id, args2: packet?._id, args3: dataSize, args4: packet._dataLength); @@ -126,7 +181,6 @@ public int TakeData(SNIPacket packet, int size) /// Size public void AppendData(byte[] data, int size) { - Debug.Assert(_data != null, "AppendData on empty or returned packet"); Buffer.BlockCopy(data, 0, _data, _headerLength + _dataLength, size); _dataLength += size; #if DEBUG @@ -152,7 +206,7 @@ public int TakeData(byte[] buffer, int dataOffset, int size) { size = _dataLength - _dataOffset; } - Debug.Assert(_data != null, "TakeData on empty or returned packet"); + Buffer.BlockCopy(_data, _headerLength + _dataOffset, buffer, dataOffset, size); _dataOffset += size; #if DEBUG @@ -180,12 +234,6 @@ public void SetHeaderActive() #endif } - public void SetDataToRemainingContents() - { - Debug.Assert(_headerLength == 0, "cannot set data to remaining contents when _headerLength is already reserved"); - _dataLength -= _dataOffset; - } - /// /// Release packet /// @@ -308,32 +356,5 @@ public async void WriteToStreamAsync(Stream stream, SNIAsyncCallback callback, S } callback(this, status); } - - public ArraySegment GetDataBuffer() - { - return new ArraySegment(_data, _headerLength + _dataOffset, DataLeft); - } - - public ArraySegment GetFreeBuffer() - { - int start = _headerLength + _dataOffset + DataLeft; - int length = _dataCapacity - start; - return new ArraySegment(_data, start, length); - } - - public static int TransferData(SNIPacket source, SNIPacket target, int maximumLength) - { - ArraySegment sourceBuffer = source.GetDataBuffer(); - ArraySegment targetBuffer = target.GetFreeBuffer(); - - int copyLength = Math.Min(Math.Min(sourceBuffer.Count, targetBuffer.Count), maximumLength); - - Buffer.BlockCopy(sourceBuffer.Array, sourceBuffer.Offset, targetBuffer.Array, targetBuffer.Offset, copyLength); - - source._dataOffset += copyLength; - target._dataLength += copyLength; - - return copyLength; - } } } diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPhysicalHandle.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPhysicalHandle.cs index 3086d50a59..ba08f99bea 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPhysicalHandle.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPhysicalHandle.cs @@ -42,10 +42,14 @@ public override SNIPacket RentPacket(int headerSize, int dataSize) Debug.Assert(packet.IsInvalid, "dequeue returned valid packet"); GC.ReRegisterForFinalize(packet); } - packet.AddHistory(true); +#if TRACE_HISTORY + if (packet._history != null) + { + packet._history.Add(new SNIPacket.History { Action = SNIPacket.History.Direction.Rent, Stack = GetStackParts(), RefCount = packet._refCount }); + } +#endif Interlocked.Add(ref packet._refCount, 1); - Debug.Assert(packet.IsActive, "SNIPacket _refcount must be 1 or a lifetime issue has occured, trace with the #TRACE_HISTORY define"); - packet.ClearPath(); + Debug.Assert(packet.IsActive, "SNIPacket _refcount must be 1 or a lifetime issue has occurred, trace with the #TRACE_HISTORY define"); #endif packet.Allocate(headerSize, dataSize); return packet; @@ -53,21 +57,38 @@ public override SNIPacket RentPacket(int headerSize, int dataSize) public override void ReturnPacket(SNIPacket packet) { - Debug.Assert(packet != null, "releasing null SNIPacket"); #if DEBUG - Debug.Assert(packet.IsActive, "SNIPacket _refcount must be 1 or a lifetime issue has occured, trace with the #TRACE_HISTORY define"); + Debug.Assert(packet != null, "releasing null SNIPacket"); + Debug.Assert(packet.IsActive, "SNIPacket _refcount must be 1 or a lifetime issue has occurred, trace with the #TRACE_HISTORY define"); Debug.Assert(ReferenceEquals(packet._owner, this), "releasing SNIPacket that belongs to another physical handle"); -#endif Debug.Assert(!packet.IsInvalid, "releasing already released SNIPacket"); +#endif packet.Release(); #if DEBUG Interlocked.Add(ref packet._refCount, -1); packet._traceTag = null; - packet.AddHistory(false); +#if TRACE_HISTORY + if (packet._history != null) + { + packet._history.Add(new SNIPacket.History { Action = SNIPacket.History.Direction.Return, Stack = GetStackParts(), RefCount = packet._refCount }); + } +#endif GC.SuppressFinalize(packet); #endif _pool.Return(packet); } + +#if DEBUG + private string GetStackParts() + { + return string.Join(Environment.NewLine, + Environment.StackTrace + .Split(new string[] { Environment.NewLine },StringSplitOptions.None) + .Skip(3) // trims off the common parts at the top of the stack so you can see what the actual caller was + .Take(7) // trims off most of the bottom of the stack because when running under xunit there's a lot of spam + ); + } +#endif } } diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNITcpHandle.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNITcpHandle.cs index ec11b3e317..d37ba9d35c 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNITcpHandle.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNITcpHandle.cs @@ -738,7 +738,7 @@ public override uint Receive(out SNIPacket packet, int timeoutInMilliseconds) packet = RentPacket(headerSize: 0, dataSize: _bufferSize); packet.ReadFromStream(_stream); - if (packet.DataLength == 0) + if (packet.Length == 0) { errorPacket = packet; packet = null; diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlClientEventSource.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlClientEventSource.cs index 203cffd705..c897b70a6d 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlClientEventSource.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlClientEventSource.cs @@ -1120,23 +1120,11 @@ internal static class EventType { private readonly long _scopeId; - public TrySNIEventScope(long scopeID) - { - _scopeId = scopeID; - } + public TrySNIEventScope(long scopeID) => _scopeId = scopeID; + public void Dispose() => + SqlClientEventSource.Log.SNIScopeLeave(string.Format("Exit SNI Scope {0}", _scopeId)); - public void Dispose() - { - if (_scopeId != 0) - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(_scopeId); - } - } - - public static TrySNIEventScope Create(string message, [System.Runtime.CompilerServices.CallerMemberName] string memberName = "") - { - return new TrySNIEventScope(SqlClientEventSource.Log.TrySNIScopeEnterEvent(message, memberName)); - } + public static TrySNIEventScope Create(string message) => new TrySNIEventScope(SqlClientEventSource.Log.SNIScopeEnter(message)); } internal readonly ref struct TryEventScope //: IDisposable diff --git a/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/MARSTest/MARSTest.cs b/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/MARSTest/MARSTest.cs index ad12902c3a..b3c874dbcd 100644 --- a/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/MARSTest/MARSTest.cs +++ b/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/MARSTest/MARSTest.cs @@ -639,5 +639,64 @@ public static async Task MarsScenarioClientJoin() Assert.Equal(companyNames[supplier], name); } } + + [ConditionalFact(typeof(DataTestUtility), nameof(DataTestUtility.AreConnStringsSetup))] + public static void MarsConcurrencyTest() + { + var table = DataTestUtility.GenerateObjectName(); + using (var conn = new SqlConnection(DataTestUtility.TCPConnectionString)) + { + conn.Open(); + using var cmd = new SqlCommand + { + Connection = conn, + CommandText = @$" + DROP TABLE IF EXISTS [{table}]; + CREATE TABLE [{table}] ( + [Id] INTEGER, + [IsDeleted] BIT + )" + }; + + cmd.ExecuteNonQuery(); + } + + var connString = new SqlConnectionStringBuilder(DataTestUtility.TCPConnectionString) { MultipleActiveResultSets = true }.ConnectionString; + using (var conn = new SqlConnection(connString)) + { + conn.Open(); + try + { + for (int i = 0; i < 5; i++) + { + Parallel.For( + 0, 300, + i => + { + using var cmd = new SqlCommand + { + Connection = conn, + CommandText = @$" + SELECT [l].[Id], [l].[IsDeleted] + FROM [{table}] AS [l] + WHERE ([l].[IsDeleted] = CAST(0 AS bit)) AND [l].[Id] IN (1, 2, 3)" + }; + + using SqlDataReader _ = cmd.ExecuteReader(); + }); + } + } + catch (Exception e) + { + Assert.False(true, "CRITIAL: Test should not fail randomly. Exception occurred: " + e.Message); + } + finally + { + using var dropConn = new SqlConnection(DataTestUtility.TCPConnectionString); + dropConn.Open(); + DataTestUtility.DropTable(dropConn, table); + } + } + } } }