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; }