internal async Task <MethodResponse> OnDirectMethodCalled(MethodRequest methodRequest, object userContext)
{
if (methodRequest == null)
{
throw new ArgumentNullException(nameof(methodRequest));
}
try
{
if (string.Equals(Constants.CloudToDeviceClearCache, methodRequest.Name, StringComparison.OrdinalIgnoreCase))
{
return(await ClearCache());
}
else if (string.Equals(Constants.CloudToDeviceDecoderElementName, methodRequest.Name, StringComparison.OrdinalIgnoreCase))
{
return(await SendCloudToDeviceMessageAsync(methodRequest));
}
this.logger.LogError($"Unknown direct method called: {methodRequest.Name}");
return(new MethodResponse((int)HttpStatusCode.BadRequest));
}
catch (Exception ex) when(ExceptionFilterUtility.False(() => this.logger.LogError(ex, $"An exception occurred on a direct method call: {ex}"),
() => this.unhandledExceptionCount.Add(1)))
{
throw;
}
}
public async Task <bool> UpdateReportedPropertiesAsync(TwinCollection reportedProperties, CancellationToken cancellationToken)
{
CancellationTokenSource cts = default;
try
{
if (cancellationToken == default)
{
cts = new CancellationTokenSource(twinUpdateTimeout);
cancellationToken = cts.Token;
}
this.logger.LogDebug("updating twin");
await this.deviceClient.UpdateReportedPropertiesAsync(reportedProperties, cancellationToken);
this.logger.LogDebug("twin updated");
return(true);
}
catch (IotHubCommunicationException ex) when(ex.InnerException is OperationCanceledException &&
ExceptionFilterUtility.True(() => this.logger.LogError($"could not update twin with error: {ex.Message}")))
{
return(false);
}
finally
{
cts?.Dispose();
}
}
public async Task <Message> ReceiveAsync(TimeSpan timeout)
{
try
{
this.logger.LogDebug($"checking cloud to device message for {timeout}");
var msg = await this.deviceClient.ReceiveAsync(timeout);
if (this.logger.IsEnabled(LogLevel.Debug))
{
if (msg == null)
{
this.logger.LogDebug("done checking cloud to device message, found no message");
}
else
{
this.logger.LogDebug($"done checking cloud to device message, found message id: {msg.MessageId ?? "undefined"}");
}
}
return(msg);
}
catch (OperationCanceledException ex) when(ExceptionFilterUtility.True(() => this.logger.LogError($"could not retrieve cloud to device message with error: {ex.Message}")))
{
return(null);
}
}
public async Task <bool> SendEventAsync(LoRaDeviceTelemetry telemetry, Dictionary <string, string> properties)
{
if (telemetry != null)
{
try
{
var messageJson = JsonConvert.SerializeObject(telemetry, Formatting.None);
using var message = new Message(Encoding.UTF8.GetBytes(messageJson));
this.logger.LogDebug($"sending message {messageJson} to hub");
message.ContentType = System.Net.Mime.MediaTypeNames.Application.Json;
message.ContentEncoding = Encoding.UTF8.BodyName;
if (properties != null)
{
foreach (var prop in properties)
{
message.Properties.Add(prop);
}
}
await this.deviceClient.SendEventAsync(message);
return(true);
}
catch (OperationCanceledException ex) when(ExceptionFilterUtility.True(() => this.logger.LogError($"could not send message to IoTHub/Edge with error: {ex.Message}")))
{
// continue
}
}
return(false);
}
public static Task RunOnThreadPool(Func <Task> task, Action <Exception> log, Counter <int>?exceptionCount) =>
Task.Run(async() =>
{
try
{
await task();
}
catch (Exception ex) when(ExceptionFilterUtility.False(() => log(ex), () => exceptionCount?.Add(1)))
{
throw;
}
});
public void False_Two_Arguments_SuccessCase()
{
// arrange
var action = new Mock <Action>();
// act
var result = ExceptionFilterUtility.False(action.Object, action.Object);
// assert
Assert.False(result);
action.Verify(a => a.Invoke(), Times.Exactly(2));
}
public void True_SuccessCase()
{
// arrange
var action = new Mock <Action>();
// act
var result = ExceptionFilterUtility.True(action.Object);
// assert
Assert.True(result);
action.Verify(a => a.Invoke(), Times.Once);
}
public async Task <bool> ValidateAsync(X509Certificate2 certificate, X509Chain?chain, SslPolicyErrors sslPolicyErrors, CancellationToken token)
{
if (certificate is null)
{
throw new ArgumentNullException(nameof(certificate));
}
if (chain is null)
{
throw new ArgumentNullException(nameof(chain));
}
var commonName = certificate.GetNameInfo(X509NameType.SimpleName, false);
var regex = Regex.Match(commonName, "([a-fA-F0-9]{2}[-:]?){8}");
var parseSuccess = StationEui.TryParse(regex.Value, out var stationEui);
if (!parseSuccess)
{
this.logger.LogError("Could not find a possible StationEui in '{CommonName}'.", commonName);
return(false);
}
using var scope = this.logger.BeginEuiScope(stationEui);
// Logging any chain related issue that is causing verification to fail
if (chain.ChainStatus.Any(s => s.Status != X509ChainStatusFlags.NoError))
{
foreach (var status in chain.ChainStatus)
{
this.logger.LogError("{Status} {StatusInformation}", status.Status, status.StatusInformation);
}
this.logger.LogError("Some errors were found in the chain.");
return(false);
}
// Additional validation is done on certificate thumprint
try
{
var thumbprints = await this.stationConfigurationService.GetAllowedClientThumbprintsAsync(stationEui, token);
var thumbprintFound = thumbprints.Any(t => t.Equals(certificate.Thumbprint, StringComparison.OrdinalIgnoreCase));
if (!thumbprintFound)
{
this.logger.LogDebug($"'{certificate.Thumbprint}' was not found as allowed thumbprint for {stationEui}");
}
return(thumbprintFound);
}
catch (Exception ex) when(ExceptionFilterUtility.False(() => this.logger.LogError(ex, "An exception occurred while processing requests: {Exception}.", ex)))
{
return(false);
}
}
/// <summary>
/// Ensures that the connection is open.
/// </summary>
public bool EnsureConnected()
{
if (this.deviceClient == null)
{
try
{
this.deviceClient = CreateDeviceClient();
this.logger.LogDebug("device client reconnected");
}
catch (ArgumentException ex) when(ExceptionFilterUtility.True(() => this.logger.LogError($"could not connect device client with error: {ex.Message}")))
{
return(false);
}
}
return(true);
}
/// <summary>
/// Method to update the desired properties.
/// We only want to update the auth code if the facadeUri was performed.
/// If the update is not acceptable we don't apply it.
/// </summary>
internal Task OnDesiredPropertiesUpdate(TwinCollection desiredProperties, object userContext)
{
try
{
_ = TryUpdateConfigurationWithDesiredProperties(desiredProperties);
}
catch (ConfigurationErrorsException ex)
{
this.logger.LogWarning($"A desired properties update was detected but the parameters are out of range with exception : {ex}");
}
catch (Exception ex) when(ExceptionFilterUtility.False(() => this.logger.LogError(ex, $"An exception occurred on desired property update: {ex}"),
() => this.unhandledExceptionCount.Add(1)))
{
throw;
}
return(Task.CompletedTask);
}
public async Task <bool> RejectAsync(Message cloudToDeviceMessage)
{
if (cloudToDeviceMessage is null)
{
throw new ArgumentNullException(nameof(cloudToDeviceMessage));
}
try
{
this.logger.LogDebug($"rejecting cloud to device message, id: {cloudToDeviceMessage.MessageId ?? "undefined"}");
await this.deviceClient.RejectAsync(cloudToDeviceMessage);
this.logger.LogDebug($"done rejecting cloud to device message, id: {cloudToDeviceMessage.MessageId ?? "undefined"}");
return(true);
}
catch (OperationCanceledException ex) when(ExceptionFilterUtility.True(() => this.logger.LogError($"could not reject cloud to device message (id: {cloudToDeviceMessage.MessageId ?? "undefined"}) with error: {ex.Message}")))
{
return(false);
}
}
internal async Task ProcessJoinRequestAsync(LoRaRequest request)
{
LoRaDevice loRaDevice = null;
var loraRegion = request.Region;
try
{
var timeWatcher = request.GetTimeWatcher();
var processingTimeout = timeWatcher.GetRemainingTimeToJoinAcceptSecondWindow() - TimeSpan.FromMilliseconds(100);
using var joinAcceptCancellationToken = new CancellationTokenSource(processingTimeout > TimeSpan.Zero ? processingTimeout : TimeSpan.Zero);
var joinReq = (LoRaPayloadJoinRequest)request.Payload;
var devEui = joinReq.DevEUI;
using var scope = this.logger.BeginDeviceScope(devEui);
this.logger.LogInformation("join request received");
if (this.concentratorDeduplication.CheckDuplicateJoin(request) is ConcentratorDeduplicationResult.Duplicate)
{
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.DeduplicationDrop);
// we do not log here as the concentratorDeduplication service already does more detailed logging
return;
}
loRaDevice = await this.deviceRegistry.GetDeviceForJoinRequestAsync(devEui, joinReq.DevNonce);
if (loRaDevice == null)
{
request.NotifyFailed(devEui.ToString(), LoRaDeviceRequestFailedReason.UnknownDevice);
// we do not log here as we assume that the deviceRegistry does a more informed logging if returning null
return;
}
if (loRaDevice.AppKey is null)
{
this.logger.LogError("join refused: missing AppKey for OTAA device");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.InvalidJoinRequest);
return;
}
var appKey = loRaDevice.AppKey.Value;
this.joinRequestCounter?.Add(1);
if (loRaDevice.AppEui != joinReq.AppEui)
{
this.logger.LogError("join refused: AppEUI for OTAA does not match device");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.InvalidJoinRequest);
return;
}
if (!joinReq.CheckMic(appKey))
{
this.logger.LogError("join refused: invalid MIC");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.JoinMicCheckFailed);
return;
}
// Make sure that is a new request and not a replay
if (loRaDevice.DevNonce is { } devNonce&& devNonce == joinReq.DevNonce)
{
if (string.IsNullOrEmpty(loRaDevice.GatewayID))
{
this.logger.LogInformation("join refused: join already processed by another gateway");
}
else
{
this.logger.LogError("join refused: DevNonce already used by this device");
}
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.JoinDevNonceAlreadyUsed);
return;
}
// Check that the device is joining through the linked gateway and not another
if (!loRaDevice.IsOurDevice)
{
this.logger.LogInformation("join refused: trying to join not through its linked gateway, ignoring join request");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.HandledByAnotherGateway);
return;
}
var netId = this.configuration.NetId;
var appNonce = new AppNonce(RandomNumberGenerator.GetInt32(toExclusive: AppNonce.MaxValue + 1));
var appSKey = OTAAKeysGenerator.CalculateAppSessionKey(appNonce, netId, joinReq.DevNonce, appKey);
var nwkSKey = OTAAKeysGenerator.CalculateNetworkSessionKey(appNonce, netId, joinReq.DevNonce, appKey);
var address = RandomNumberGenerator.GetInt32(toExclusive: DevAddr.MaxNetworkAddress + 1);
// The 7 LBS of the NetID become the NwkID of a DevAddr:
var devAddr = new DevAddr(unchecked ((byte)netId.NetworkId), address);
var oldDevAddr = loRaDevice.DevAddr;
if (!timeWatcher.InTimeForJoinAccept())
{
this.receiveWindowMisses?.Add(1);
// in this case it's too late, we need to break and avoid saving twins
this.logger.LogInformation("join refused: processing of the join request took too long, sending no message");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.ReceiveWindowMissed);
return;
}
var updatedProperties = new LoRaDeviceJoinUpdateProperties
{
DevAddr = devAddr,
NwkSKey = nwkSKey,
AppSKey = appSKey,
AppNonce = appNonce,
DevNonce = joinReq.DevNonce,
NetId = netId,
Region = request.Region.LoRaRegion,
PreferredGatewayID = this.configuration.GatewayID,
};
if (loRaDevice.ClassType == LoRaDeviceClassType.C)
{
updatedProperties.SavePreferredGateway = true;
updatedProperties.SaveRegion = true;
updatedProperties.StationEui = request.StationEui;
}
DeviceJoinInfo deviceJoinInfo = null;
if (request.Region.LoRaRegion == LoRaRegionType.CN470RP2)
{
if (request.Region.TryGetJoinChannelIndex(request.RadioMetadata.Frequency, out var channelIndex))
{
updatedProperties.CN470JoinChannel = channelIndex;
deviceJoinInfo = new DeviceJoinInfo(channelIndex);
}
else
{
this.logger.LogError("failed to retrieve the join channel index for device");
}
}
var deviceUpdateSucceeded = await loRaDevice.UpdateAfterJoinAsync(updatedProperties, joinAcceptCancellationToken.Token);
if (!deviceUpdateSucceeded)
{
this.logger.LogError("join refused: join request could not save twin");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.IoTHubProblem);
return;
}
var windowToUse = timeWatcher.ResolveJoinAcceptWindowToUse();
if (windowToUse is null)
{
this.receiveWindowMisses?.Add(1);
this.logger.LogInformation("join refused: processing of the join request took too long, sending no message");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.ReceiveWindowMissed);
return;
}
this.deviceRegistry.UpdateDeviceAfterJoin(loRaDevice, oldDevAddr);
// Build join accept downlink message
// Build the DlSettings fields that is a superposition of RX2DR and RX1DROffset field
var dlSettings = new byte[1];
if (loRaDevice.DesiredRX2DataRate.HasValue)
{
if (request.Region.DRtoConfiguration.ContainsKey(loRaDevice.DesiredRX2DataRate.Value))
{
dlSettings[0] = (byte)((byte)loRaDevice.DesiredRX2DataRate & 0b00001111);
}
else
{
this.logger.LogError("twin RX2 DR value is not within acceptable values");
}
}
if (request.Region.IsValidRX1DROffset(loRaDevice.DesiredRX1DROffset))
{
var rx1droffset = (byte)(loRaDevice.DesiredRX1DROffset << 4);
dlSettings[0] = (byte)(dlSettings[0] + rx1droffset);
}
else
{
this.logger.LogError("twin RX1 offset DR value is not within acceptable values");
}
// The following DesiredRxDelay is different than the RxDelay to be passed to Serialize function
// This one is a delay between TX and RX for any message to be processed by joining device
// The field accepted by Serialize method is an indication of the delay (compared to receive time of join request)
// of when the message Join Accept message should be sent
var loraSpecDesiredRxDelay = RxDelay.RxDelay0;
if (Enum.IsDefined(loRaDevice.DesiredRXDelay))
{
loraSpecDesiredRxDelay = loRaDevice.DesiredRXDelay;
}
else
{
this.logger.LogError("twin RX delay value is not within acceptable values");
}
var loRaPayloadJoinAccept = new LoRaPayloadJoinAccept(
netId, // NETID 0 / 1 is default test
devAddr, // todo add device address management
appNonce,
dlSettings,
loraSpecDesiredRxDelay,
null);
if (!loraRegion.TryGetDownstreamChannelFrequency(request.RadioMetadata.Frequency, upstreamDataRate: request.RadioMetadata.DataRate, deviceJoinInfo: deviceJoinInfo, downstreamFrequency: out var freq))
{
this.logger.LogError("could not resolve DR and/or frequency for downstream");
request.NotifyFailed(loRaDevice, LoRaDeviceRequestFailedReason.InvalidUpstreamMessage);
return;
}
var joinAcceptBytes = loRaPayloadJoinAccept.Serialize(appKey);
var rx1 = windowToUse is not ReceiveWindow2
? new ReceiveWindow(loraRegion.GetDownstreamDataRate(request.RadioMetadata.DataRate, loRaDevice.ReportedRX1DROffset), freq)
: (ReceiveWindow?)null;
var rx2 = new ReceiveWindow(loraRegion.GetDownstreamRX2DataRate(this.configuration.Rx2DataRate, null, deviceJoinInfo, this.logger),
loraRegion.GetDownstreamRX2Freq(this.configuration.Rx2Frequency, deviceJoinInfo, this.logger));
var downlinkMessage = new DownlinkMessage(joinAcceptBytes,
request.RadioMetadata.UpInfo.Xtime,
rx1,
rx2,
loRaDevice.DevEUI,
loraRegion.JoinAcceptDelay1,
loRaDevice.ClassType,
request.StationEui,
request.RadioMetadata.UpInfo.AntennaPreference);
this.receiveWindowHits?.Add(1, KeyValuePair.Create(MetricRegistry.ReceiveWindowTagName, (object)windowToUse));
_ = request.DownstreamMessageSender.SendDownstreamAsync(downlinkMessage);
request.NotifySucceeded(loRaDevice, downlinkMessage);
if (this.logger.IsEnabled(LogLevel.Debug))
{
var jsonMsg = JsonConvert.SerializeObject(downlinkMessage);
this.logger.LogDebug($"{MacMessageType.JoinAccept} {jsonMsg}");
}
else
{
this.logger.LogInformation("join accepted");
}
}
catch (Exception ex) when
(ExceptionFilterUtility.True(() => this.logger.LogError(ex, $"failed to handle join request. {ex.Message}", LogLevel.Error),
() => this.unhandledExceptionCount?.Add(1)))
{
request.NotifyFailed(loRaDevice, ex);
throw;
}
}
/// <summary>
/// Prepare the Mac Commands to be sent in the downstream message.
/// </summary>
private static ICollection <MacCommand> PrepareMacCommandAnswer(
IEnumerable <MacCommand> requestedMacCommands,
IEnumerable <MacCommand> serverMacCommands,
LoRaRequest loRaRequest,
LoRaADRResult loRaADRResult,
ILogger logger)
{
var cids = new HashSet <Cid>();
var macCommands = new List <MacCommand>();
if (requestedMacCommands != null)
{
foreach (var requestedMacCommand in requestedMacCommands)
{
switch (requestedMacCommand.Cid)
{
case Cid.LinkCheckCmd:
case Cid.Zero:
case Cid.One:
case Cid.LinkADRCmd:
if (loRaRequest != null)
{
var linkCheckAnswer = new LinkCheckAnswer(checked ((byte)loRaRequest.Region.GetModulationMargin(loRaRequest.RadioMetadata.DataRate, loRaRequest.RadioMetadata.UpInfo.SignalNoiseRatio)), 1);
if (cids.Add(Cid.LinkCheckCmd))
{
macCommands.Add(linkCheckAnswer);
logger.LogInformation($"answering to a MAC command request {linkCheckAnswer}");
}
}
break;
case Cid.DutyCycleCmd:
case Cid.RXParamCmd:
case Cid.DevStatusCmd:
case Cid.NewChannelCmd:
case Cid.RXTimingCmd:
case Cid.TxParamSetupCmd:
default:
break;
}
}
}
if (serverMacCommands != null)
{
foreach (var macCmd in serverMacCommands)
{
if (macCmd != null)
{
try
{
if (cids.Add(macCmd.Cid))
{
macCommands.Add(macCmd);
}
else
{
logger.LogError($"could not send the cloud to device MAC command {macCmd.Cid}, as such a property was already present in the message. Please resend the cloud to device message");
}
logger.LogInformation($"cloud to device MAC command {macCmd.Cid} received {macCmd}");
}
catch (MacCommandException ex) when(ExceptionFilterUtility.True(() => logger.LogError(ex.ToString())))
{
// continue
}
}
}
}
// ADR Part.
// Currently only replying on ADR Req
if (loRaADRResult?.CanConfirmToDevice == true)
{
const int placeholderChannel = 25;
var linkADR = new LinkADRRequest((byte)loRaADRResult.DataRate, (byte)loRaADRResult.TxPower, placeholderChannel, 0, (byte)loRaADRResult.NbRepetition);
macCommands.Add(linkADR);
logger.LogInformation($"performing a rate adaptation: DR {loRaADRResult.DataRate}, transmit power {loRaADRResult.TxPower}, #repetition {loRaADRResult.NbRepetition}");
}
return(macCommands);
}
protected async Task CreateDevicesAsync(IReadOnlyList <IoTHubDeviceInfo> devices)
{
List <Task <LoRaDevice> > initTasks = null;
List <Task <bool> > refreshTasks = null;
var deviceCreated = 0;
if (devices?.Count > 0)
{
initTasks = new List <Task <LoRaDevice> >(devices.Count);
foreach (var foundDevice in devices)
{
using var scope = this.logger.BeginDeviceScope(foundDevice.DevEUI);
// Only create devices that does not exist in the cache
if (!this.loraDeviceCache.TryGetByDevEui(foundDevice.DevEUI, out var cachedDevice))
{
initTasks.Add(this.deviceFactory.CreateAndRegisterAsync(foundDevice, CancellationToken.None));
}
else
{
if (cachedDevice.DevAddr is null)
{
// device in cache from a previous join that we didn't complete
// (lost race with another gw) - refresh the twins now and keep it
// in the cache
refreshTasks ??= new List <Task <bool> >();
refreshTasks.Add(cachedDevice.InitializeAsync(this.configuration, CancellationToken.None));
this.logger.LogDebug("refreshing device to fetch DevAddr");
}
}
}
try
{
_ = await Task.WhenAll(initTasks);
if (refreshTasks != null)
{
_ = await Task.WhenAll(refreshTasks);
}
}
catch (LoRaProcessingException ex) when(ex.ErrorCode == LoRaProcessingErrorCode.DeviceInitializationFailed &&
ExceptionFilterUtility.True(() => this.logger.LogError($"one or more device initializations failed: {ex}")))
{
// continue
HasLoadingDeviceError = true;
}
if (initTasks.Count > 0)
{
foreach (var deviceTask in initTasks)
{
if (deviceTask.IsCompletedSuccessfully)
{
var device = await deviceTask;
// run initializers
InitializeDevice(device);
deviceCreated++;
}
}
}
}
CreatedDevicesCount = deviceCreated;
}