From 827b0deb81c5bfe0864f0707c104f0415c1df1bd Mon Sep 17 00:00:00 2001 From: Wraith2 Date: Thu, 25 Feb 2021 22:44:57 +0000 Subject: [PATCH 1/5] rework MARSConnection state machine and flow changes through managed SNI --- .../src/Microsoft.Data.SqlClient.csproj | 1 + .../Microsoft/Data/SqlClient/SNI/SNICommon.cs | 3 +- .../Data/SqlClient/SNI/SNIMarsConnection.cs | 463 +++++++++--------- .../Data/SqlClient/SNI/SNIMarsHandle.cs | 2 +- .../Data/SqlClient/SNI/SNINpHandle.cs | 2 +- .../Data/SqlClient/SNI/SNIPacket.Debug.cs | 188 +++++++ .../Microsoft/Data/SqlClient/SNI/SNIPacket.cs | 110 ++--- .../Data/SqlClient/SNI/SNIPhysicalHandle.cs | 36 +- .../Data/SqlClient/SNI/SNITcpHandle.cs | 2 +- .../Data/SqlClient/TdsParserStateObject.cs | 5 + .../Data/SqlClient/SqlClientEventSource.cs | 22 +- 11 files changed, 497 insertions(+), 337 deletions(-) create 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 c5fa057a37..7f9a7d2dc9 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft.Data.SqlClient.csproj +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft.Data.SqlClient.csproj @@ -530,6 +530,7 @@ + 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 8ae171fc68..6934192718 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 @@ -90,8 +90,7 @@ public void Write(Span bytes) /// /// SMUX packet flags /// - [Flags] - internal enum SNISMUXFlags + internal enum SNISMUXFlags : uint { 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 395cfed4be..2a63240f95 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,28 +14,15 @@ namespace Microsoft.Data.SqlClient.SNI /// internal class SNIMarsConnection { - 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 readonly Guid _connectionId; + private readonly Dictionary _sessions; private SNIHandle _lowerHandle; - private ushort _nextSessionId = 0; - private int _currentHeaderByteCount = 0; - private int _dataBytesLeft = 0; - private SNIPacket _currentPacket; + private ushort _nextSessionId; /// /// Connection ID /// - public Guid ConnectionId - { - get - { - return _connectionId; - } - } + public Guid ConnectionId => _connectionId; public int ProtocolVersion => _lowerHandle.ProtocolVersion; @@ -45,8 +32,15 @@ public Guid ConnectionId /// Lower handle public SNIMarsConnection(SNIHandle lowerHandle) { + _connectionId = Guid.NewGuid(); + _sessions = new Dictionary(); + _state = State.Header; + _headerCount = 0; + _headerBytes = new byte[SNISMUXHeader.HEADER_LENGTH]; + _header = new SNISMUXHeader(); + _nextSessionId = 0; _lowerHandle = lowerHandle; - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "Created MARS Session Id {0}", args0: ConnectionId); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "Created MARS Session Id {0}", args0: ConnectionId); _lowerHandle.SetAsyncCallbacks(HandleReceiveComplete, HandleSendComplete); } @@ -57,7 +51,7 @@ public SNIMarsHandle CreateMarsSession(object callbackObject, bool async) ushort sessionId = _nextSessionId++; SNIMarsHandle handle = new SNIMarsHandle(this, sessionId, callbackObject, async); _sessions.Add(sessionId, handle); - 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); + 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); return handle; } } @@ -68,23 +62,18 @@ public SNIMarsHandle CreateMarsSession(object callbackObject, bool async) /// public uint StartReceive() { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { SNIPacket packet = null; if (ReceiveAsync(ref packet) == TdsEnums.SNI_SUCCESS_IO_PENDING) { - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Success IO pending.", args0: ConnectionId); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, Success IO pending.", args0: ConnectionId); return TdsEnums.SNI_SUCCESS_IO_PENDING; } - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Connection not usable.", args0: ConnectionId); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), 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); - } } /// @@ -94,18 +83,13 @@ public uint StartReceive() /// SNI error code public uint Send(SNIPacket packet) { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { lock (this) { return _lowerHandle.Send(packet); } } - finally - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); - } } /// @@ -116,18 +100,13 @@ public uint Send(SNIPacket packet) /// SNI error code public uint SendAsync(SNIPacket packet, SNIAsyncCallback callback) { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { lock (this) { return _lowerHandle.SendAsync(packet, callback); } } - finally - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); - } } /// @@ -137,14 +116,13 @@ public uint SendAsync(SNIPacket packet, SNIAsyncCallback callback) /// SNI error code public uint ReceiveAsync(ref SNIPacket packet) { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { if (packet != null) { ReturnPacket(packet); #if DEBUG - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Packet {1} returned", args0: ConnectionId, args1: packet?._id); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, Packet {1} returned", args0: ConnectionId, args1: packet?._id); #endif packet = null; } @@ -153,15 +131,11 @@ public uint ReceiveAsync(ref SNIPacket packet) { var response = _lowerHandle.ReceiveAsync(ref packet); #if DEBUG - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Received new packet {1}", args0: ConnectionId, args1: packet?._id); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, Received new packet {1}", args0: ConnectionId, args1: packet?._id); #endif return response; } } - finally - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); - } } /// @@ -170,18 +144,13 @@ public uint ReceiveAsync(ref SNIPacket packet) /// SNI error status public uint CheckConnection() { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { lock (this) { return _lowerHandle.CheckConnection(); } } - finally - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); - } } /// @@ -190,17 +159,21 @@ public uint CheckConnection() public void HandleReceiveError(SNIPacket packet) { Debug.Assert(Monitor.IsEntered(this), "HandleReceiveError was called without being locked."); + if (!Monitor.IsEntered(this)) + { + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, function was called without being locked.", args0: ConnectionId); + } foreach (SNIMarsHandle handle in _sessions.Values) { if (packet.HasCompletionCallback) { handle.HandleReceiveError(packet); #if DEBUG - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Packet {1} has Completion Callback", args0: ConnectionId, args1: packet?._id); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Packet {1} has Completion Callback", args0: ConnectionId, args1: packet?._id); } else { - 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); + 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); #endif } } @@ -219,228 +192,250 @@ public void HandleSendComplete(SNIPacket packet, uint sniErrorCode) } /// - /// Process a receive completion + /// Enable SSL /// - /// SNI packet - /// SNI error code - public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) + public uint EnableSsl(uint options) + { + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + { + return _lowerHandle.EnableSsl(options); + } + } + + /// + /// Disable SSL + /// + public void DisableSsl() { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { - SNISMUXHeader currentHeader = null; - SNIPacket currentPacket = null; - SNIMarsHandle currentSession = null; + _lowerHandle.DisableSsl(); + } + } + public SNIPacket RentPacket(int headerSize, int dataSize) => _lowerHandle.RentPacket(headerSize, dataSize); + + public void ReturnPacket(SNIPacket packet) => _lowerHandle.ReturnPacket(packet); + +#if DEBUG + /// + /// Test handle for killing underlying connection + /// + public void KillConnection() + { + using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) + { + _lowerHandle.KillConnection(); + } + } +#endif + + private enum State : uint + { + Header = 1, + Payload = 2, + Dispatch = 3 + } + + private enum LoopState : uint + { + Run, + Recieve, + Finish, + Error + } + + + // the following variables are used only inside HandleRecieveComplete + // all access to these variables must be performed under lock(this) because + // RecieveAsync can immediately return a new packet causing reentrant behaviour + // without the lock. + private State _state; + + 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))) + { 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); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); return; } } - while (true) + LoopState loopState = LoopState.Run; + lock (this) { - lock (this) + while (loopState == LoopState.Run) { - if (_currentHeaderByteCount != SNISMUXHeader.HEADER_LENGTH) + switch (_state) { - currentHeader = null; - currentPacket = null; - currentSession = null; - - while (_currentHeaderByteCount != SNISMUXHeader.HEADER_LENGTH) - { - int bytesTaken = packet.TakeData(_headerBytes, _currentHeaderByteCount, SNISMUXHeader.HEADER_LENGTH - _currentHeaderByteCount); - _currentHeaderByteCount += bytesTaken; + case State.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; + _partial = RentPacket(headerSize: 0, dataSize: _payloadLength); + _state = State.Payload; + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, header complete, _payloadLength {1}", args0: _lowerHandle?.ConnectionId, args1: _payloadLength); + goto case State.Payload; + } + else + { + loopState = LoopState.Recieve; + } + break; - if (bytesTaken == 0) + case State.Payload: + if (packet.DataLeft == _payloadLength && _partial == null) { - 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 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 when + _partial = packet; + packet = null; + _partial.SetDataToRemainingContents(); + _state = State.Dispatch; + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, forwarding packet contents", args0: _lowerHandle?.ConnectionId, args1: _header?.sessionId); + goto case State.Dispatch; + } + else + { + 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 (sniErrorCode == TdsEnums.SNI_SUCCESS_IO_PENDING) + if (_payloadCount == _payloadLength) { - return; + // payload is complete so dispatch the current packet + _state = State.Dispatch; + goto case State.Dispatch; + } + else if (packet.DataLeft == 0) + { + // no more data in this packet so wait for a new one + loopState = LoopState.Recieve; + } + else + { + // start the loop again and decode the next packet in the input + _headerCount = 0; + _state = State.Header; } - - 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; + break; - if (_currentHeader.flags == (byte)SNISMUXFlags.SMUX_DATA) - { - if (_dataBytesLeft > 0) - { - int length = packet.TakeData(_currentPacket, _dataBytesLeft); - _dataBytesLeft -= length; - - if (_dataBytesLeft > 0) + case State.Dispatch: + if (_sessions.TryGetValue(_header.sessionId, out SNIMarsHandle session)) { - 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) + 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) { - return; + case SNISMUXFlags.SMUX_DATA: + session.HandleReceiveComplete(_partial, _header); + // do not return the _partial packet, the receiver is responsible for returning the + // packet once it has been used because it can take sync and async paths from here + _partial = null; + 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); + break; + + case SNISMUXFlags.SMUX_ACK: + ReturnPacket(_partial); + _partial = null; + try + { + session.HandleAck(_header.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); + } + 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; } + // partial packet has been fully reconstructed and dispatched so change to header state + // to be ready to decode another smux header + _headerCount = 0; + _state = State.Header; + + if (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); + } + // no more data in this packet or the packet has been forwarded so exit + // the loop and wait for a new packet to be recieved + loopState = LoopState.Recieve; + } + } + else + { + SNILoadHandle.SingletonInstance.LastError = new SNIError(SNIProviders.SMUX_PROV, 0, SNICommon.InvalidParameterError, string.Empty); HandleReceiveError(packet); - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); - return; + 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; + loopState = LoopState.Error; } - } - } - - _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); + break; } } + } - if (currentHeader.flags == (byte)SNISMUXFlags.SMUX_DATA) + if (loopState == LoopState.Recieve) + { + if (packet != null) { - 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); + Debug.Assert(packet.DataLeft == 0, "loop exit with data remaining"); + ReturnPacket(packet); + packet = null; } - if (_currentHeader.flags == (byte)SNISMUXFlags.SMUX_ACK) + if (ReceiveAsync(ref packet) == TdsEnums.SNI_SUCCESS_IO_PENDING) { - 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; + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, SMUX DATA Header SNI Packet received with code {1}", args0: ConnectionId, args1: TdsEnums.SNI_SUCCESS_IO_PENDING); + packet = null; } - - lock (this) + else { - 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; - } + HandleReceiveError(packet); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: sniErrorCode); } } } - finally - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); - } } - /// - /// Enable SSL - /// - public uint EnableSsl(uint options) - { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try - { - return _lowerHandle.EnableSsl(options); - } - finally - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); - } - } - - /// - /// Disable SSL - /// - public void DisableSsl() - { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try - { - _lowerHandle.DisableSsl(); - } - finally - { - SqlClientEventSource.Log.TrySNIScopeLeaveEvent(scopeID); - } - } - - public SNIPacket RentPacket(int headerSize, int dataSize) - { - return _lowerHandle.RentPacket(headerSize, dataSize); - } - - public void ReturnPacket(SNIPacket packet) - { - _lowerHandle.ReturnPacket(packet); - } - -#if DEBUG - /// - /// Test handle for killing underlying connection - /// - public void KillConnection() - { - long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); - try - { - _lowerHandle.KillConnection(); - } - finally - { - 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 1c1523d73e..b6ac514dc9 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 @@ -146,7 +146,7 @@ private SNIPacket SetPacketSMUXHeader(SNIPacket packet) { Debug.Assert(packet.ReservedHeaderSize == SNISMUXHeader.HEADER_LENGTH, "mars handle attempting to smux packet without smux reservation"); - SetupSMUXHeader(packet.Length, SNISMUXFlags.SMUX_DATA); + SetupSMUXHeader(packet.DataLength, SNISMUXFlags.SMUX_DATA); _currentHeader.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); packet.SetHeaderActive(); #if DEBUG 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 4571dd470b..a11779870b 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 @@ -199,7 +199,7 @@ public override uint Receive(out SNIPacket packet, int timeout) packet.ReadFromStream(_stream); SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "Connection Id {0}, Rented and read packet, dataLeft {1}", args0: _connectionId, args1: packet?.DataLeft); - if (packet.Length == 0) + if (packet.DataLength == 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 new file mode 100644 index 0000000000..2bb58834ed --- /dev/null +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.Debug.cs @@ -0,0 +1,188 @@ +// 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 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 7fe953d8d8..836b4c3485 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,11 +2,8 @@ // 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; @@ -17,7 +14,7 @@ namespace Microsoft.Data.SqlClient.SNI /// /// SNI Packet /// - internal sealed class SNIPacket + internal sealed partial class SNIPacket { private const string s_className = nameof(SNIPacket); private int _dataLength; // the length of the data in the data segment, advanced by Append-ing data, does not include smux header length @@ -28,62 +25,7 @@ internal sealed 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(s_className, 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(s_className, 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; @@ -92,7 +34,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 @@ -102,7 +44,7 @@ public SNIPacket() /// /// Length of data /// - public int Length => _dataLength; + public int DataLength => _dataLength; /// /// Packet validity @@ -144,7 +86,7 @@ public void Allocate(int headerLength, int dataLength) _dataOffset = 0; _headerLength = headerLength; #if DEBUG - SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "Connection Id {0}, Packet Id {1} allocated with _headerLength {2}, _dataCapacity {3}", args0: _owner?.ConnectionId, args1: _id, args2: _headerLength, args3: _dataCapacity); + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIPacket), EventType.INFO, "Connection Id {0}, Packet Id {1} allocated with _headerLength {2}, _dataCapacity {3}", args0: _owner?.ConnectionId, args1: _id, args2: _headerLength, args3: _dataCapacity); #endif } @@ -155,7 +97,8 @@ 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) { - Buffer.BlockCopy(_data, _headerLength, buffer, 0, _dataLength); + Debug.Assert(_data != null, "GetData on empty or returned packet"); + Buffer.BlockCopy(_data, _headerLength + _dataOffset, buffer, 0, _dataLength); dataSize = _dataLength; } @@ -167,7 +110,9 @@ public void GetData(byte[] buffer, ref int dataSize) /// Amount of data taken public int TakeData(SNIPacket packet, int size) { - int dataSize = TakeData(packet._data, packet._headerLength + packet._dataLength, 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"); packet._dataLength += dataSize; #if DEBUG SqlClientEventSource.Log.TrySNITraceEvent(s_className, 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); @@ -182,6 +127,7 @@ 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 @@ -207,7 +153,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 @@ -235,6 +181,12 @@ 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 /// @@ -357,5 +309,33 @@ 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 ca11e8c4ac..37e7469548 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,14 +42,10 @@ public override SNIPacket RentPacket(int headerSize, int dataSize) Debug.Assert(packet.IsInvalid, "dequeue returned valid packet"); GC.ReRegisterForFinalize(packet); } -#if TRACE_HISTORY - if (packet._history != null) - { - packet._history.Add(new SNIPacket.History { Action = SNIPacket.History.Direction.Rent, Stack = GetStackParts(), RefCount = packet._refCount }); - } -#endif + packet.AddHistory(true); Interlocked.Add(ref packet._refCount, 1); - Debug.Assert(packet.IsActive, "SNIPacket _refcount must be 1 or a lifetime issue has occurred, trace with the #TRACE_HISTORY define"); + Debug.Assert(packet.IsActive, "SNIPacket _refcount must be 1 or a lifetime issue has occured, trace with the #TRACE_HISTORY define"); + packet.ClearPath(); #endif packet.Allocate(headerSize, dataSize); return packet; @@ -57,38 +53,22 @@ public override SNIPacket RentPacket(int headerSize, int dataSize) public override void ReturnPacket(SNIPacket packet) { -#if DEBUG 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"); +#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(ReferenceEquals(packet._owner, this), "releasing SNIPacket that belongs to another physical handle"); - Debug.Assert(!packet.IsInvalid, "releasing already released SNIPacket"); #endif + Debug.Assert(!packet.IsInvalid, "releasing already released SNIPacket"); packet.Release(); #if DEBUG Interlocked.Add(ref packet._refCount, -1); packet._traceTag = null; -#if TRACE_HISTORY - if (packet._history != null) - { - packet._history.Add(new SNIPacket.History { Action = SNIPacket.History.Direction.Return, Stack = GetStackParts(), RefCount = packet._refCount }); - } -#endif + packet.AddHistory(false); + //packet.PushPath(new StackTrace().ToString()); 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 d2a8341c0f..214b867369 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 @@ -740,7 +740,7 @@ public override uint Receive(out SNIPacket packet, int timeoutInMilliseconds) packet = RentPacket(headerSize: 0, dataSize: _bufferSize); packet.ReadFromStream(_stream); - if (packet.Length == 0) + if (packet.DataLength == 0) { errorPacket = packet; packet = null; diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs index 8645cee07e..f27a87a71e 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs @@ -2532,6 +2532,11 @@ internal void ReadSni(TaskCompletionSource completion) Debug.Assert(IsValidPacket(readPacket), "ReadNetworkPacket should not have been null on this async operation!"); // Evaluate this condition for MANAGED_SNI. This may not be needed because the network call is happening Async and only the callback can receive a success. ReadAsyncCallback(IntPtr.Zero, readPacket, 0); + + if (!IsPacketEmpty(readPacket)) + { + ReleasePacket(readPacket); + } } else if (TdsEnums.SNI_SUCCESS_IO_PENDING != error) { // FAILURE! 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 4de98e5379..0d7f4ad368 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlClientEventSource.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlClientEventSource.cs @@ -1105,14 +1105,26 @@ internal static class EventType public const string ERR = " | ERR | "; } - internal readonly struct SNIEventScope : IDisposable + internal readonly struct TrySNIEventScope : IDisposable { private readonly long _scopeId; - public SNIEventScope(long scopeID) => _scopeId = scopeID; - public void Dispose() => - SqlClientEventSource.Log.SNIScopeLeave(string.Format("Exit SNI Scope {0}", _scopeId)); + public TrySNIEventScope(long scopeID) + { + _scopeId = scopeID; + } - public static SNIEventScope Create(string message) => new SNIEventScope(SqlClientEventSource.Log.SNIScopeEnter(message)); + 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)); + } } } From 64c180a93b803381bfb6c88df57088e044ac71d5 Mon Sep 17 00:00:00 2001 From: Wraith2 Date: Sat, 27 Feb 2021 01:04:38 +0000 Subject: [PATCH 2/5] address feedback --- .../src/Microsoft/Data/SqlClient/SNI/SNIMarsConnection.cs | 4 ++-- .../src/Microsoft/Data/SqlClient/SNI/SNIPacket.Debug.cs | 5 ++--- .../netcore/src/Microsoft/Data/SqlClient/SNI/SNIPacket.cs | 1 - .../src/Microsoft/Data/SqlClient/SNI/SNIPhysicalHandle.cs | 1 - 4 files changed, 4 insertions(+), 7 deletions(-) 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 2a63240f95..f220ddd576 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 @@ -306,7 +306,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) { // 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 when + // fiddled the data pointer so that it skips the header data _partial = packet; packet = null; _partial.SetDataToRemainingContents(); @@ -388,7 +388,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) _headerCount = 0; _state = State.Header; - if (packet==null || packet.DataLeft == 0) + if (packet == null || packet.DataLeft == 0) { if (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 index 2bb58834ed..904940f19e 100644 --- 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 @@ -6,8 +6,8 @@ // 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 and then when you hit a breakpoint or assertion failure inspect the _path variable - // to see the pushed entries since the packet was rented. + // 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; @@ -182,7 +182,6 @@ private string GetStackParts() ); } #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 836b4c3485..973be0f61c 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 @@ -336,6 +336,5 @@ public static int TransferData(SNIPacket source, SNIPacket target, int maximumLe 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 37e7469548..9c6ceb2a98 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 @@ -65,7 +65,6 @@ public override void ReturnPacket(SNIPacket packet) Interlocked.Add(ref packet._refCount, -1); packet._traceTag = null; packet.AddHistory(false); - //packet.PushPath(new StackTrace().ToString()); GC.SuppressFinalize(packet); #endif _pool.Return(packet); From 282f985b351809fd9ed10731f639a8ce24945eb4 Mon Sep 17 00:00:00 2001 From: Wraith2 Date: Mon, 1 Mar 2021 23:38:24 +0000 Subject: [PATCH 3/5] additional changes to state machine and locking dependency asserts --- .../Microsoft/Data/SqlClient/SNI/SNICommon.cs | 66 ++- .../Data/SqlClient/SNI/SNIMarsConnection.cs | 401 +++++++++++------- .../Data/SqlClient/SNI/SNIMarsHandle.cs | 55 ++- 3 files changed, 334 insertions(+), 188 deletions(-) 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 6934192718..0fca7f161d 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,30 +35,40 @@ internal enum SNIProviders /// /// SMUX packet header /// - internal sealed class SNISMUXHeader + internal struct SNISMUXHeader { public const int HEADER_LENGTH = 16; - public byte SMID; - public byte flags; - public ushort sessionId; - public uint length; - public uint sequenceNumber; - public uint highwater; + 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 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); @@ -66,25 +76,47 @@ 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; + } } /// 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 f220ddd576..25c3ddd555 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 @@ -26,6 +26,8 @@ internal class SNIMarsConnection public int ProtocolVersion => _lowerHandle.ProtocolVersion; + public object DemuxerSync => this; + /// /// Constructor /// @@ -34,10 +36,9 @@ public SNIMarsConnection(SNIHandle lowerHandle) { _connectionId = Guid.NewGuid(); _sessions = new Dictionary(); - _state = State.Header; + _demuxState = DemuxState.Header; _headerCount = 0; _headerBytes = new byte[SNISMUXHeader.HEADER_LENGTH]; - _header = new SNISMUXHeader(); _nextSessionId = 0; _lowerHandle = lowerHandle; SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "Created MARS Session Id {0}", args0: ConnectionId); @@ -46,7 +47,7 @@ public SNIMarsConnection(SNIHandle lowerHandle) public SNIMarsHandle CreateMarsSession(object callbackObject, bool async) { - lock (this) + lock (DemuxerSync) { ushort sessionId = _nextSessionId++; SNIMarsHandle handle = new SNIMarsHandle(this, sessionId, callbackObject, async); @@ -85,7 +86,7 @@ public uint Send(SNIPacket packet) { using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { - lock (this) + lock (DemuxerSync) { return _lowerHandle.Send(packet); } @@ -102,7 +103,7 @@ public uint SendAsync(SNIPacket packet, SNIAsyncCallback callback) { using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { - lock (this) + lock (DemuxerSync) { return _lowerHandle.SendAsync(packet, callback); } @@ -127,7 +128,7 @@ public uint ReceiveAsync(ref SNIPacket packet) packet = null; } - lock (this) + lock (DemuxerSync) { var response = _lowerHandle.ReceiveAsync(ref packet); #if DEBUG @@ -146,7 +147,7 @@ public uint CheckConnection() { using (TrySNIEventScope.Create(nameof(SNIMarsConnection))) { - lock (this) + lock (DemuxerSync) { return _lowerHandle.CheckConnection(); } @@ -158,8 +159,8 @@ public uint CheckConnection() /// public void HandleReceiveError(SNIPacket packet) { - Debug.Assert(Monitor.IsEntered(this), "HandleReceiveError was called without being locked."); - if (!Monitor.IsEntered(this)) + 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); } @@ -230,16 +231,18 @@ public void KillConnection() } #endif - private enum State : uint + private enum DemuxState : uint { Header = 1, Payload = 2, Dispatch = 3 } - private enum LoopState : uint + private enum State : uint { - Run, + Demux, + HandleAck, + HandleData, Recieve, Finish, Error @@ -247,10 +250,10 @@ private enum LoopState : uint // the following variables are used only inside HandleRecieveComplete - // all access to these variables must be performed under lock(this) because + // 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 State _state; + private DemuxState _demuxState; private byte[] _headerBytes; private int _headerCount; @@ -258,6 +261,7 @@ private enum LoopState : uint private int _payloadLength; private int _payloadCount; + private SNIPacket _partial; public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) @@ -266,7 +270,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) { if (sniErrorCode != TdsEnums.SNI_SUCCESS) { - lock (this) + 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); @@ -274,166 +278,253 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) } } - LoopState loopState = LoopState.Run; - lock (this) + State state = State.Demux; + State nextState = State.Demux; + + SNISMUXHeader handleHeader = default; + SNIMarsHandle handleSession = null; + SNIPacket handlePacket = null; + + while (state != State.Error && state != State.Finish) { - while (loopState == LoopState.Run) + switch (state) { - switch (_state) - { - case State.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; - _partial = RentPacket(headerSize: 0, dataSize: _payloadLength); - _state = State.Payload; - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, header complete, _payloadLength {1}", args0: _lowerHandle?.ConnectionId, args1: _payloadLength); - goto case State.Payload; - } - else + case State.Demux: + lock (DemuxerSync) + { + switch (_demuxState) { - loopState = LoopState.Recieve; - } - break; + 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.Recieve; + } + break; - case State.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(); - _state = State.Dispatch; - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, forwarding packet contents", args0: _lowerHandle?.ConnectionId, args1: _header?.sessionId); - goto case State.Dispatch; - } - else - { - 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 - _state = State.Dispatch; - goto case State.Dispatch; - } - else if (packet.DataLeft == 0) - { - // no more data in this packet so wait for a new one - loopState = LoopState.Recieve; - } - else - { - // start the loop again and decode the next packet in the input - _headerCount = 0; - _state = State.Header; - } - } + 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); - break; + if (_payloadCount == _payloadLength) + { + // payload is complete so dispatch the current packet + _demuxState = DemuxState.Dispatch; + state = State.Recieve; + 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.Recieve; + } + 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; + } + } - case State.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: - session.HandleReceiveComplete(_partial, _header); - // do not return the _partial packet, the receiver is responsible for returning the - // packet once it has been used because it can take sync and async paths from here - _partial = null; - 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); - break; - - case SNISMUXFlags.SMUX_ACK: - ReturnPacket(_partial); - _partial = null; - try + 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) { - session.HandleAck(_header.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); + 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.Recieve; + } + 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.Recieve; + } + 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; } - catch (Exception e) + + // 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)) { - SNICommon.ReportSNIError(SNIProviders.SMUX_PROV, SNICommon.InternalExceptionError, e); + 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.Recieve; } - 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; - } - - // partial packet has been fully reconstructed and dispatched so change to header state - // to be ready to decode another smux header - _headerCount = 0; - _state = State.Header; - - if (packet == null || packet.DataLeft == 0) - { - if (packet != null) + + } + else { - SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.INFO, "MARS Session Id {0}, run out of data , queuing receive", args0: _lowerHandle?.ConnectionId, args1: _header?.sessionId); + 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; } - // no more data in this packet or the packet has been forwarded so exit - // the loop and wait for a new packet to be recieved - loopState = LoopState.Recieve; - } + 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.Recieve: + 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 { - 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; - loopState = LoopState.Error; + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNIMarsConnection), EventType.ERR, "MARS Session Id {0}, Handled receive error code: {1}", args0: _lowerHandle?.ConnectionId, args1: receiveResult); } - break; - } + } + state = State.Finish; + break; } } - if (loopState == LoopState.Recieve) - { - if (packet != null) - { - Debug.Assert(packet.DataLeft == 0, "loop exit with data remaining"); - ReturnPacket(packet); - packet = null; - } - - if (ReceiveAsync(ref packet) == 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: TdsEnums.SNI_SUCCESS_IO_PENDING); - 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: sniErrorCode); - } - } } } 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 b6ac514dc9..bdbbc1179e 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 @@ -26,7 +26,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; @@ -55,6 +55,11 @@ 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 + if (_connection != null && Monitor.IsEntered(_connection.DemuxerSync)) + { + throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + } long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -106,8 +111,8 @@ private void SendControlPacket(SNISMUXFlags flags) #endif lock (this) { - SetupSMUXHeader(0, flags); - _currentHeader.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); + SNISMUXHeader header = SetupSMUXHeader(0, flags); + header.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); packet.SetHeaderActive(); } @@ -124,17 +129,22 @@ private void SendControlPacket(SNISMUXFlags flags) } } - private void SetupSMUXHeader(int length, SNISMUXFlags flags) + private SNISMUXHeader SetupSMUXHeader(int length, SNISMUXFlags flags) { Debug.Assert(Monitor.IsEntered(this), "must take lock on self before updating smux 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; + 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; } /// @@ -145,9 +155,10 @@ private void 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"); - SetupSMUXHeader(packet.DataLength, SNISMUXFlags.SMUX_DATA); - _currentHeader.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); + SNISMUXHeader header = SetupSMUXHeader(packet.DataLength, SNISMUXFlags.SMUX_DATA); + header.Write(packet.GetHeaderBuffer(SNISMUXHeader.HEADER_LENGTH)); packet.SetHeaderActive(); #if DEBUG SqlClientEventSource.Log.TrySNITraceEvent(s_className, EventType.INFO, "MARS Session Id {0}, Setting SMUX_DATA header in current header for packet {1}", args0: ConnectionId, args1: packet?._id); @@ -290,6 +301,10 @@ private uint SendPendingPackets() /// SNI error code public override uint SendAsync(SNIPacket packet, SNIAsyncCallback callback = null) { + if (Monitor.IsEntered(_connection.DemuxerSync)) + { + throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + } long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -423,6 +438,10 @@ public void HandleSendComplete(SNIPacket packet, uint sniErrorCode) /// Send highwater mark public void HandleAck(uint highwater) { + if (Monitor.IsEntered(_connection.DemuxerSync)) + { + throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + } long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -449,15 +468,19 @@ public void HandleAck(uint highwater) /// SMUX header public void HandleReceiveComplete(SNIPacket packet, SNISMUXHeader header) { + if (Monitor.IsEntered(_connection.DemuxerSync)) + { + throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + } long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { lock (this) { - if (_sendHighwater != header.highwater) + if (_sendHighwater != header.Highwater) { - SqlClientEventSource.Log.TrySNITraceEvent(s_className, 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(s_className, 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) From 1ad1379ae1e4e98c0b58301c735b92d3f2ee1687 Mon Sep 17 00:00:00 2001 From: Wraith2 Date: Fri, 25 Jun 2021 19:37:23 +0100 Subject: [PATCH 4/5] add dedicate sync object and user assertions in place of exceptions --- .../Data/SqlClient/SNI/SNIMarsConnection.cs | 4 +++- .../Data/SqlClient/SNI/SNIMarsHandle.cs | 20 ++++--------------- 2 files changed, 7 insertions(+), 17 deletions(-) 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 25c3ddd555..19609d4080 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,6 +14,7 @@ namespace Microsoft.Data.SqlClient.SNI /// internal class SNIMarsConnection { + private readonly object _sync; private readonly Guid _connectionId; private readonly Dictionary _sessions; private SNIHandle _lowerHandle; @@ -26,7 +27,7 @@ internal class SNIMarsConnection public int ProtocolVersion => _lowerHandle.ProtocolVersion; - public object DemuxerSync => this; + public object DemuxerSync => _sync; /// /// Constructor @@ -34,6 +35,7 @@ internal class SNIMarsConnection /// Lower handle public SNIMarsConnection(SNIHandle lowerHandle) { + _sync = new object(); _connectionId = Guid.NewGuid(); _sessions = new Dictionary(); _demuxState = DemuxState.Header; 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 bdbbc1179e..efa69ca664 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 @@ -56,10 +56,7 @@ 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 - if (_connection != null && Monitor.IsEntered(_connection.DemuxerSync)) - { - throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); - } + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -301,10 +298,7 @@ private uint SendPendingPackets() /// SNI error code public override uint SendAsync(SNIPacket packet, SNIAsyncCallback callback = null) { - if (Monitor.IsEntered(_connection.DemuxerSync)) - { - throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); - } + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -438,10 +432,7 @@ public void HandleSendComplete(SNIPacket packet, uint sniErrorCode) /// Send highwater mark public void HandleAck(uint highwater) { - if (Monitor.IsEntered(_connection.DemuxerSync)) - { - throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); - } + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -468,10 +459,7 @@ public void HandleAck(uint highwater) /// SMUX header public void HandleReceiveComplete(SNIPacket packet, SNISMUXHeader header) { - if (Monitor.IsEntered(_connection.DemuxerSync)) - { - throw new InvalidOperationException("SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); - } + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { From 9e808bea338c4f2ec68267dfe1067bc4ba59b9ef Mon Sep 17 00:00:00 2001 From: Wraith2 Date: Tue, 13 Jul 2021 12:25:18 +0100 Subject: [PATCH 5/5] address feedback --- .../Data/SqlClient/SNI/SNIMarsConnection.cs | 16 ++++++++-------- .../Data/SqlClient/SNI/SNIMarsHandle.cs | 8 ++++---- 2 files changed, 12 insertions(+), 12 deletions(-) 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 19609d4080..22e0c6eab9 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 @@ -245,7 +245,7 @@ private enum State : uint Demux, HandleAck, HandleData, - Recieve, + Receive, Finish, Error } @@ -312,7 +312,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) } else { - state = State.Recieve; + state = State.Receive; } break; @@ -346,14 +346,14 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) { // payload is complete so dispatch the current packet _demuxState = DemuxState.Dispatch; - state = State.Recieve; + 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.Recieve; + state = State.Receive; } else { @@ -388,7 +388,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) } else { - nextState = State.Recieve; + nextState = State.Receive; } break; @@ -407,7 +407,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) } else { - nextState = State.Recieve; + nextState = State.Receive; } break; @@ -438,7 +438,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) { 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.Recieve; + state = State.Receive; } } @@ -500,7 +500,7 @@ public void HandleReceiveComplete(SNIPacket packet, uint sniErrorCode) nextState = State.Finish; break; - case State.Recieve: + case State.Receive: if (packet != null) { Debug.Assert(packet.DataLeft == 0, "loop exit with data remaining"); 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 efa69ca664..353c5240b4 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 @@ -56,7 +56,7 @@ 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 be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -298,7 +298,7 @@ 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 be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -432,7 +432,7 @@ 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 be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try { @@ -459,7 +459,7 @@ 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 be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); + Debug.Assert(_connection != null && Monitor.IsEntered(_connection.DemuxerSync), "SNIMarsHandle.HandleRecieveComplete should be called while holding the SNIMarsConnection.DemuxerSync because it can cause deadlocks"); long scopeID = SqlClientEventSource.Log.TrySNIScopeEnterEvent(s_className); try {