Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor(iot-device): Add additional logging statement to disposal flow #2414

Merged
merged 4 commits into from
May 26, 2022
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -101,6 +101,14 @@ public async Task<string> GetTokenAsync(string iotHub)
{
if (_isDisposed)
{
if (Logging.IsEnabled)
{
Logging.Error(
this,
$"Encountered {nameof(ObjectDisposedException)} - The authentication method instance has already been disposed, so this client is no longer usable.",
nameof(GetTokenAsync));
}

throw new ObjectDisposedException(GetType().Name, "The authentication method instance has already been disposed, so this client is no longer usable. " +
"Please close and dispose your current client instance. To continue carrying out operations from your device/ module, " +
"create a new authentication method instance and use it for reinitializing your client.");
Expand Down Expand Up @@ -177,15 +185,30 @@ private void UpdateTimeBufferSeconds(int ttl)
/// <param name="disposing">true to release both managed and unmanaged resources; false to release only unmanaged resources.</param>
protected virtual void Dispose(bool disposing)
{
if (!_isDisposed)
try
{
if (disposing)
if (Logging.IsEnabled)
{
_lock?.Dispose();
_lock = null;
Logging.Enter(this, $"Disposed={_isDisposed}; disposing={disposing}", $"{nameof(AuthenticationWithTokenRefresh)}.{nameof(Dispose)}");
}

_isDisposed = true;
if (!_isDisposed)
{
if (disposing)
{
_lock?.Dispose();
_lock = null;
}

_isDisposed = true;
}
}
finally
{
if (Logging.IsEnabled)
{
Logging.Exit(this, $"Disposed={_isDisposed}; disposing={disposing}", $"{nameof(AuthenticationWithTokenRefresh)}.{nameof(Dispose)}");
}
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
using System.Net;
using System.Threading.Tasks;
using Microsoft.Azure.Devices.Client.Extensions;
using Microsoft.Azure.Devices.Shared;

namespace Microsoft.Azure.Devices.Client
{
Expand Down Expand Up @@ -34,25 +35,40 @@ internal DeviceAuthenticationWithSakRefresh(
///<inheritdoc/>
protected override Task<string> SafeCreateNewToken(string iotHub, int suggestedTimeToLive)
{
var builder = new SharedAccessSignatureBuilder
try
{
Key = _connectionString.SharedAccessKey,
TimeToLive = TimeSpan.FromSeconds(suggestedTimeToLive),
};
if (Logging.IsEnabled)
{
Logging.Enter(this, iotHub, suggestedTimeToLive, nameof(SafeCreateNewToken));
}

if (_connectionString.SharedAccessKeyName == null)
{
builder.Target = "{0}/devices/{1}".FormatInvariant(
iotHub,
WebUtility.UrlEncode(DeviceId));
var builder = new SharedAccessSignatureBuilder
{
Key = _connectionString.SharedAccessKey,
TimeToLive = TimeSpan.FromSeconds(suggestedTimeToLive),
};

if (_connectionString.SharedAccessKeyName == null)
{
builder.Target = "{0}/devices/{1}".FormatInvariant(
iotHub,
WebUtility.UrlEncode(DeviceId));
}
else
{
builder.KeyName = _connectionString.SharedAccessKeyName;
builder.Target = _connectionString.Audience;
}

return Task.FromResult(builder.ToSignature());
}
else
finally
{
builder.KeyName = _connectionString.SharedAccessKeyName;
builder.Target = _connectionString.Audience;
if (Logging.IsEnabled)
{
Logging.Exit(this, iotHub, suggestedTimeToLive, nameof(SafeCreateNewToken));
}
}

return Task.FromResult(builder.ToSignature());
}
}
}
27 changes: 20 additions & 7 deletions iothub/device/src/Pipeline/DefaultDelegatingHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -215,17 +215,30 @@ protected void ThrowIfDisposed()

protected virtual void Dispose(bool disposing)
{
if (_disposed)
try
{
return;
if (Logging.IsEnabled)
{
Logging.Enter(this, $"Disposed={_disposed}; disposing={disposing}", $"{nameof(DefaultDelegatingHandler)}.{nameof(Dispose)}");
}

if (!_disposed)
{
if (disposing)
{
_innerHandler?.Dispose();
}

_disposed = true;
}
}

if (disposing)
finally
{
_innerHandler?.Dispose();
if (Logging.IsEnabled)
{
Logging.Exit(this, $"Disposed={_disposed}; disposing={disposing}", $"{nameof(DefaultDelegatingHandler)}.{nameof(Dispose)}");
}
}

_disposed = true;
}

~DefaultDelegatingHandler()
Expand Down
37 changes: 26 additions & 11 deletions iothub/device/src/Pipeline/RetryDelegatingHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1076,22 +1076,37 @@ private void HandleConnectionStatusExceptions(Exception exception, bool retryAtt

protected override void Dispose(bool disposing)
{
if (_disposed)
try
{
return;
}
if (Logging.IsEnabled)
{
Logging.Enter(this, $"{nameof(DefaultDelegatingHandler)}.Disposed={_disposed}; disposing={disposing}", $"{nameof(RetryDelegatingHandler)}.{nameof(Dispose)}");
}

base.Dispose(disposing);
if (disposing)
if (!_disposed)
{
base.Dispose(disposing);
if (disposing)
{
_handleDisconnectCts?.Cancel();
_handleDisconnectCts?.Dispose();
if (_handlerSemaphore != null && _handlerSemaphore.CurrentCount == 0)
{
_handlerSemaphore.Release();
}
_handlerSemaphore?.Dispose();
_handlerSemaphore = null;
}

// the _disposed flag is inherited from the base class DefaultDelegatingHandler and is finally set to null there.
}
}
finally
{
_handleDisconnectCts?.Cancel();
_handleDisconnectCts?.Dispose();
if (_handlerSemaphore != null && _handlerSemaphore.CurrentCount == 0)
if (Logging.IsEnabled)
{
_handlerSemaphore.Release();
Logging.Exit(this, $"{nameof(DefaultDelegatingHandler)}.Disposed={_disposed}; disposing={disposing}", $"{nameof(RetryDelegatingHandler)}.{nameof(Dispose)}");
}
_handlerSemaphore?.Dispose();
_handlerSemaphore = null;
}
}
}
Expand Down
27 changes: 21 additions & 6 deletions iothub/device/src/Pipeline/TransportHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -25,15 +25,30 @@ public override Task WaitForTransportClosedAsync()

protected override void Dispose(bool disposing)
{
if (_disposed)
try
{
return;
}
if (Logging.IsEnabled)
{
Logging.Enter(this, $"{nameof(DefaultDelegatingHandler)}.Disposed={_disposed}; disposing={disposing}", $"{nameof(TransportHandler)}.{nameof(Dispose)}");
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why DefaultDelegatingHandler?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The _disposed parameter referenced throughout our delegating handler pipeline is actually the protected variable defined in DefaultDelegatingHandler:

This, along with the way base.Dispose() and inherited.Dispose() are mixed in our pipeline disposal flow is something I'm looking to refactor.

}

if (!_disposed)
{
base.Dispose(disposing);
if (disposing)
{
OnTransportClosedGracefully();
}

base.Dispose(disposing);
if (disposing)
// the _disposed flag is inherited from the base class DefaultDelegatingHandler and is finally set to null there.
}
}
finally
{
OnTransportClosedGracefully();
if (Logging.IsEnabled)
{
Logging.Exit(this, $"{nameof(DefaultDelegatingHandler)}.Disposed={_disposed}; disposing={disposing}", $"{nameof(TransportHandler)}.{nameof(Dispose)}");
}
}
}

Expand Down
34 changes: 23 additions & 11 deletions iothub/device/src/Transport/Amqp/AmqpAuthenticationRefresher.cs
Original file line number Diff line number Diff line change
Expand Up @@ -102,7 +102,9 @@ private async Task RefreshLoopAsync(DateTime refreshesOn, CancellationToken canc
catch (IotHubCommunicationException ex)
{
if (Logging.IsEnabled)
Logging.Info(this, refreshesOn, $"Refresh token failed {ex}");
{
Logging.Error(this, refreshesOn, $"Refresh token failed {ex}");
}
}
finally
{
Expand All @@ -129,21 +131,31 @@ public void Dispose()

private void Dispose(bool disposing)
{
if (_disposed)
try
{
return;
}
if (Logging.IsEnabled)
{
Logging.Enter(this, $"Disposed={_disposed}; disposing={disposing}", $"{nameof(AmqpAuthenticationRefresher)}.{nameof(Dispose)}");
}

if (Logging.IsEnabled)
Logging.Info(this, disposing, nameof(Dispose));
if (!_disposed)
{
if (disposing)
{
StopLoop();
_amqpIotCbsTokenProvider?.Dispose();
}

if (disposing)
_disposed = true;
}
}
finally
{
StopLoop();
_amqpIotCbsTokenProvider?.Dispose();
if (Logging.IsEnabled)
{
Logging.Exit(this, $"Disposed={_disposed}; disposing={disposing}", $"{nameof(AmqpAuthenticationRefresher)}.{nameof(Dispose)}");
}
}

_disposed = true;
}
}
}
38 changes: 24 additions & 14 deletions iothub/device/src/Transport/Amqp/AmqpConnectionHolder.cs
Original file line number Diff line number Diff line change
Expand Up @@ -105,27 +105,37 @@ public void Dispose()

private void Dispose(bool disposing)
{
if (_disposed)
try
{
return;
}
if (Logging.IsEnabled)
{
Logging.Enter(this, $"Disposed={_disposed}; disposing={disposing}", $"{nameof(AmqpConnectionHolder)}.{nameof(Dispose)}");
}

if (Logging.IsEnabled)
Logging.Info(this, disposing, nameof(Dispose));
if (!_disposed)
{
if (disposing)
{
_amqpIotConnection?.SafeClose();
_lock?.Dispose();
_amqpIotConnector?.Dispose();
lock (_unitsLock)
{
_amqpUnits.Clear();
}
_amqpAuthenticationRefresher?.Dispose();
}

if (disposing)
_disposed = true;
}
}
finally
{
_amqpIotConnection?.SafeClose();
_lock?.Dispose();
_amqpIotConnector?.Dispose();
lock (_unitsLock)
if (Logging.IsEnabled)
{
_amqpUnits.Clear();
Logging.Exit(this, $"Disposed={_disposed}; disposing={disposing}", $"{nameof(AmqpConnectionHolder)}.{nameof(Dispose)}");
}
_amqpAuthenticationRefresher?.Dispose();
}

_disposed = true;
}

public async Task<IAmqpAuthenticationRefresher> CreateRefresherAsync(IDeviceIdentity deviceIdentity, CancellationToken cancellationToken)
Expand Down
29 changes: 19 additions & 10 deletions iothub/device/src/Transport/Amqp/AmqpTransportHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -616,23 +616,32 @@ private void TwinMessageListener(Twin twin, string correlationId, TwinCollection

protected override void Dispose(bool disposing)
{
lock (_lock)
try
{
if (_disposed)
if (Logging.IsEnabled)
{
return;
Logging.Enter(this, $"{nameof(DefaultDelegatingHandler)}.Disposed={_disposed}; disposing={disposing}", $"{nameof(AmqpTransportHandler)}.{nameof(Dispose)}");
}

base.Dispose(disposing);
lock (_lock)
{
if (!_disposed)
{
if (disposing)
{
_closed = true;
AmqpUnitManager.GetInstance()?.RemoveAmqpUnit(_amqpUnit);
}
}

// the _disposed flag is inherited from the base class DefaultDelegatingHandler and is finally set to null there.
}
}
finally
{
if (Logging.IsEnabled)
Logging.Info(this, nameof(disposing));

if (disposing)
{
_closed = true;
AmqpUnitManager.GetInstance()?.RemoveAmqpUnit(_amqpUnit);
_disposed = true;
abhipsaMisra marked this conversation as resolved.
Show resolved Hide resolved
Logging.Exit(this, $"{nameof(DefaultDelegatingHandler)}.Disposed={_disposed}; disposing={disposing}", $"{nameof(AmqpTransportHandler)}.{nameof(Dispose)}");
}
}
}
Expand Down
Loading