/// <summary>
/// Process OTAA join request
/// </summary>
async Task <DownlinkPktFwdMessage> ProcessJoinRequestAsync(Rxpk rxpk, LoRaPayloadJoinRequest joinReq, DateTime startTimeProcessing)
{
var timeWatcher = new LoRaOperationTimeWatcher(this.loraRegion, startTimeProcessing);
using (var processLogger = new ProcessLogger(timeWatcher))
{
byte[] udpMsgForPktForwarder = new byte[0];
var devEUI = joinReq.GetDevEUIAsString();
var appEUI = joinReq.GetAppEUIAsString();
// set context to logger
processLogger.SetDevEUI(devEUI);
var devNonce = joinReq.GetDevNonceAsString();
Logger.Log(devEUI, $"join request received", LogLevel.Information);
var loRaDevice = await this.deviceRegistry.GetDeviceForJoinRequestAsync(devEUI, appEUI, devNonce);
if (loRaDevice == null)
{
return(null);
}
if (string.IsNullOrEmpty(loRaDevice.AppKey))
{
Logger.Log(loRaDevice.DevEUI, "join refused: missing AppKey for OTAA device", LogLevel.Error);
return(null);
}
if (loRaDevice.AppEUI != appEUI)
{
Logger.Log(devEUI, "join refused: AppEUI for OTAA does not match device", LogLevel.Error);
return(null);
}
if (!joinReq.CheckMic(loRaDevice.AppKey))
{
Logger.Log(devEUI, "join refused: invalid MIC", LogLevel.Error);
return(null);
}
// Make sure that is a new request and not a replay
if (!string.IsNullOrEmpty(loRaDevice.DevNonce) && loRaDevice.DevNonce == devNonce)
{
Logger.Log(devEUI, "join refused: DevNonce already used by this device", LogLevel.Information);
loRaDevice.IsOurDevice = false;
return(null);
}
// Check that the device is joining through the linked gateway and not another
if (!string.IsNullOrEmpty(loRaDevice.GatewayID) && !string.Equals(loRaDevice.GatewayID, this.configuration.GatewayID, StringComparison.InvariantCultureIgnoreCase))
{
Logger.Log(devEUI, $"join refused: trying to join not through its linked gateway, ignoring join request", LogLevel.Information);
loRaDevice.IsOurDevice = false;
return(null);
}
var netIdBytes = BitConverter.GetBytes(this.configuration.NetId);
var netId = new byte[3]
{
netIdBytes[0],
netIdBytes[1],
netIdBytes[2]
};
var appNonce = OTAAKeysGenerator.GetAppNonce();
var appNonceBytes = LoRaTools.Utils.ConversionHelper.StringToByteArray(appNonce);
var appKeyBytes = LoRaTools.Utils.ConversionHelper.StringToByteArray(loRaDevice.AppKey);
var appSKey = OTAAKeysGenerator.CalculateKey(new byte[1] {
0x02
}, appNonceBytes, netId, joinReq.DevNonce, appKeyBytes);
var nwkSKey = OTAAKeysGenerator.CalculateKey(new byte[1] {
0x01
}, appNonceBytes, netId, joinReq.DevNonce, appKeyBytes);
var devAddr = OTAAKeysGenerator.GetNwkId(netId);
if (!timeWatcher.InTimeForJoinAccept())
{
// in this case it's too late, we need to break and avoid saving twins
Logger.Log(devEUI, $"join refused: processing of the join request took too long, sending no message", LogLevel.Information);
return(null);
}
Logger.Log(loRaDevice.DevEUI, $"saving join properties twins", LogLevel.Debug);
var deviceUpdateSucceeded = await loRaDevice.UpdateAfterJoinAsync(devAddr, nwkSKey, appSKey, appNonce, devNonce, LoRaTools.Utils.ConversionHelper.ByteArrayToString(netId));
Logger.Log(loRaDevice.DevEUI, $"done saving join properties twins", LogLevel.Debug);
if (!deviceUpdateSucceeded)
{
Logger.Log(devEUI, $"join refused: join request could not save twins", LogLevel.Error);
return(null);
}
var windowToUse = timeWatcher.ResolveJoinAcceptWindowToUse(loRaDevice);
if (windowToUse == 0)
{
Logger.Log(devEUI, $"join refused: processing of the join request took too long, sending no message", LogLevel.Information);
return(null);
}
double freq = 0;
string datr = null;
uint tmst = 0;
if (windowToUse == 1)
{
try
{
datr = this.loraRegion.GetDownstreamDR(rxpk);
freq = this.loraRegion.GetDownstreamChannelFrequency(rxpk);
}
catch (RegionLimitException ex)
{
Logger.Log(devEUI, ex.ToString(), LogLevel.Error);
}
// set tmst for the normal case
tmst = rxpk.Tmst + this.loraRegion.Join_accept_delay1 * 1000000;
}
else
{
Logger.Log(devEUI, $"processing of the join request took too long, using second join accept receive window", LogLevel.Information);
tmst = rxpk.Tmst + this.loraRegion.Join_accept_delay2 * 1000000;
if (string.IsNullOrEmpty(this.configuration.Rx2DataRate))
{
Logger.Log(devEUI, $"using standard second receive windows for join request", LogLevel.Information);
// using EU fix DR for RX2
freq = this.loraRegion.RX2DefaultReceiveWindows.frequency;
datr = this.loraRegion.DRtoConfiguration[RegionFactory.CurrentRegion.RX2DefaultReceiveWindows.dr].configuration;
}
else
{
Logger.Log(devEUI, $"using custom second receive windows for join request", LogLevel.Information);
freq = this.configuration.Rx2DataFrequency;
datr = this.configuration.Rx2DataRate;
}
}
loRaDevice.IsOurDevice = true;
this.deviceRegistry.UpdateDeviceAfterJoin(loRaDevice);
// Build join accept downlink message
Array.Reverse(netId);
Array.Reverse(appNonceBytes);
return(this.CreateJoinAcceptDownlinkMessage(
netId,
loRaDevice.AppKey,
devAddr,
appNonceBytes,
datr,
freq,
tmst,
devEUI));
}
}
/// <summary>
/// Process LoRa message where the payload is of type LoRaPayloadData
/// </summary>
async Task <DownlinkPktFwdMessage> ProcessDataMessageAsync(LoRaTools.LoRaPhysical.Rxpk rxpk, LoRaPayloadData loraPayload, DateTime startTime)
{
var devAddr = loraPayload.DevAddr;
var timeWatcher = new LoRaOperationTimeWatcher(this.loraRegion, startTime);
using (var processLogger = new ProcessLogger(timeWatcher, devAddr))
{
if (!this.IsValidNetId(loraPayload.GetDevAddrNetID(), this.configuration.NetId))
{
Logger.Log(ConversionHelper.ByteArrayToString(devAddr), "device is using another network id, ignoring this message", LogLevel.Debug);
processLogger.LogLevel = LogLevel.Debug;
return(null);
}
// Find device that matches:
// - devAddr
// - mic check (requires: loraDeviceInfo.NwkSKey or loraDeviceInfo.AppKey, rxpk.LoraPayload.Mic)
// - gateway id
var loRaDevice = await this.deviceRegistry.GetDeviceForPayloadAsync(loraPayload);
if (loRaDevice == null)
{
Logger.Log(ConversionHelper.ByteArrayToString(devAddr), $"device is not from our network, ignoring message", LogLevel.Information);
return(null);
}
// Add context to logger
processLogger.SetDevEUI(loRaDevice.DevEUI);
var isMultiGateway = !string.Equals(loRaDevice.GatewayID, this.configuration.GatewayID, StringComparison.InvariantCultureIgnoreCase);
var frameCounterStrategy = isMultiGateway ? this.frameCounterUpdateStrategyFactory.GetMultiGatewayStrategy() : this.frameCounterUpdateStrategyFactory.GetSingleGatewayStrategy();
var payloadFcnt = loraPayload.GetFcnt();
var requiresConfirmation = loraPayload.IsConfirmed();
using (new LoRaDeviceFrameCounterSession(loRaDevice, frameCounterStrategy))
{
// Leaf devices that restart lose the counter. In relax mode we accept the incoming frame counter
// ABP device does not reset the Fcnt so in relax mode we should reset for 0 (LMIC based) or 1
var isFrameCounterFromNewlyStartedDevice = false;
if (payloadFcnt <= 1)
{
if (loRaDevice.IsABP)
{
if (loRaDevice.IsABPRelaxedFrameCounter && loRaDevice.FCntUp >= 0 && payloadFcnt <= 1)
{
// known problem when device restarts, starts fcnt from zero
_ = frameCounterStrategy.ResetAsync(loRaDevice);
isFrameCounterFromNewlyStartedDevice = true;
}
}
else if (loRaDevice.FCntUp == payloadFcnt && payloadFcnt == 0)
{
// Some devices start with frame count 0
isFrameCounterFromNewlyStartedDevice = true;
}
}
// Reply attack or confirmed reply
// Confirmed resubmit: A confirmed message that was received previously but we did not answer in time
// Device will send it again and we just need to return an ack (but also check for C2D to send it over)
var isConfirmedResubmit = false;
if (!isFrameCounterFromNewlyStartedDevice && payloadFcnt <= loRaDevice.FCntUp)
{
// if it is confirmed most probably we did not ack in time before or device lost the ack packet so we should continue but not send the msg to iothub
if (requiresConfirmation && payloadFcnt == loRaDevice.FCntUp)
{
if (!loRaDevice.ValidateConfirmResubmit(payloadFcnt))
{
Logger.Log(loRaDevice.DevEUI, $"resubmit from confirmed message exceeds threshold of {LoRaDevice.MaxConfirmationResubmitCount}, message ignored, msg: {payloadFcnt} server: {loRaDevice.FCntUp}", LogLevel.Debug);
processLogger.LogLevel = LogLevel.Debug;
return(null);
}
isConfirmedResubmit = true;
Logger.Log(loRaDevice.DevEUI, $"resubmit from confirmed message detected, msg: {payloadFcnt} server: {loRaDevice.FCntUp}", LogLevel.Information);
}
else
{
Logger.Log(loRaDevice.DevEUI, $"invalid frame counter, message ignored, msg: {payloadFcnt} server: {loRaDevice.FCntUp}", LogLevel.Information);
return(null);
}
}
var fcntDown = 0;
// If it is confirmed it require us to update the frame counter down
// Multiple gateways: in redis, otherwise in device twin
if (requiresConfirmation)
{
fcntDown = await frameCounterStrategy.NextFcntDown(loRaDevice, payloadFcnt);
// Failed to update the fcnt down
// In multi gateway scenarios it means the another gateway was faster than using, can stop now
if (fcntDown <= 0)
{
// update our fcntup anyway?
// loRaDevice.SetFcntUp(payloadFcnt);
Logger.Log(loRaDevice.DevEUI, "another gateway has already sent ack or downlink msg", LogLevel.Information);
return(null);
}
Logger.Log(loRaDevice.DevEUI, $"down frame counter: {loRaDevice.FCntDown}", LogLevel.Information);
}
if (!isConfirmedResubmit)
{
var validFcntUp = isFrameCounterFromNewlyStartedDevice || (payloadFcnt > loRaDevice.FCntUp);
if (validFcntUp)
{
Logger.Log(loRaDevice.DevEUI, $"valid frame counter, msg: {payloadFcnt} server: {loRaDevice.FCntUp}", LogLevel.Information);
object payloadData = null;
// if it is an upward acknowledgement from the device it does not have a payload
// This is confirmation from leaf device that he received a C2D confirmed
// if a message payload is null we don't try to decrypt it.
if (loraPayload.Frmpayload.Length != 0)
{
byte[] decryptedPayloadData = null;
try
{
decryptedPayloadData = loraPayload.GetDecryptedPayload(loRaDevice.AppSKey);
}
catch (Exception ex)
{
Logger.Log(loRaDevice.DevEUI, $"failed to decrypt message: {ex.Message}", LogLevel.Error);
}
var fportUp = loraPayload.GetFPort();
if (string.IsNullOrEmpty(loRaDevice.SensorDecoder))
{
Logger.Log(loRaDevice.DevEUI, $"no decoder set in device twin. port: {fportUp}", LogLevel.Debug);
payloadData = Convert.ToBase64String(decryptedPayloadData);
}
else
{
Logger.Log(loRaDevice.DevEUI, $"decoding with: {loRaDevice.SensorDecoder} port: {fportUp}", LogLevel.Debug);
payloadData = await this.payloadDecoder.DecodeMessageAsync(decryptedPayloadData, fportUp, loRaDevice.SensorDecoder);
}
}
if (!await this.SendDeviceEventAsync(loRaDevice, rxpk, payloadData, loraPayload, timeWatcher))
{
// failed to send event to IoT Hub, stop now
return(null);
}
loRaDevice.SetFcntUp(payloadFcnt);
}
else
{
Logger.Log(loRaDevice.DevEUI, $"invalid frame counter, msg: {payloadFcnt} server: {loRaDevice.FCntUp}", LogLevel.Information);
}
}
// We check if we have time to futher progress or not
// C2D checks are quite expensive so if we are really late we just stop here
var timeToSecondWindow = timeWatcher.GetRemainingTimeToReceiveSecondWindow(loRaDevice);
if (timeToSecondWindow < LoRaOperationTimeWatcher.ExpectedTimeToPackageAndSendMessage)
{
if (requiresConfirmation)
{
Logger.Log(loRaDevice.DevEUI, $"too late for down message ({timeWatcher.GetElapsedTime()}), sending only ACK to gateway", LogLevel.Information);
}
return(null);
}
// If it is confirmed and
// - Downlink is disabled for the device or
// - we don't have time to check c2d and send to device we return now
if (requiresConfirmation && (!loRaDevice.DownlinkEnabled || timeToSecondWindow.Subtract(LoRaOperationTimeWatcher.ExpectedTimeToPackageAndSendMessage) <= LoRaOperationTimeWatcher.MinimumAvailableTimeToCheckForCloudMessage))
{
return(this.CreateDownlinkMessage(
null,
loRaDevice,
rxpk,
loraPayload,
timeWatcher,
devAddr,
false, // fpending
(ushort)fcntDown));
}
// Flag indicating if there is another C2D message waiting
var fpending = false;
// Contains the Cloud to message we need to send
Message cloudToDeviceMessage = null;
if (loRaDevice.DownlinkEnabled)
{
// ReceiveAsync has a longer timeout
// But we wait less that the timeout (available time before 2nd window)
// if message is received after timeout, keep it in loraDeviceInfo and return the next call
var timeAvailableToCheckCloudToDeviceMessages = timeWatcher.GetAvailableTimeToCheckCloudToDeviceMessage(loRaDevice);
if (timeAvailableToCheckCloudToDeviceMessages >= LoRaOperationTimeWatcher.MinimumAvailableTimeToCheckForCloudMessage)
{
cloudToDeviceMessage = await loRaDevice.ReceiveCloudToDeviceAsync(timeAvailableToCheckCloudToDeviceMessages);
if (cloudToDeviceMessage != null && !this.ValidateCloudToDeviceMessage(loRaDevice, cloudToDeviceMessage))
{
_ = loRaDevice.CompleteCloudToDeviceMessageAsync(cloudToDeviceMessage);
cloudToDeviceMessage = null;
}
if (cloudToDeviceMessage != null)
{
if (!requiresConfirmation)
{
// The message coming from the device was not confirmed, therefore we did not computed the frame count down
// Now we need to increment because there is a C2D message to be sent
fcntDown = await frameCounterStrategy.NextFcntDown(loRaDevice, payloadFcnt);
if (fcntDown == 0)
{
// We did not get a valid frame count down, therefore we should not process the message
_ = loRaDevice.AbandonCloudToDeviceMessageAsync(cloudToDeviceMessage);
cloudToDeviceMessage = null;
}
else
{
requiresConfirmation = true;
}
Logger.Log(loRaDevice.DevEUI, $"down frame counter: {loRaDevice.FCntDown}", LogLevel.Information);
}
// Checking again if cloudToDeviceMessage is valid because the fcntDown resolution could have failed,
// causing us to drop the message
if (cloudToDeviceMessage != null)
{
var remainingTimeForFPendingCheck = timeWatcher.GetRemainingTimeToReceiveSecondWindow(loRaDevice) - (LoRaOperationTimeWatcher.CheckForCloudMessageCallEstimatedOverhead + LoRaOperationTimeWatcher.MinimumAvailableTimeToCheckForCloudMessage);
if (remainingTimeForFPendingCheck >= LoRaOperationTimeWatcher.MinimumAvailableTimeToCheckForCloudMessage)
{
var additionalMsg = await loRaDevice.ReceiveCloudToDeviceAsync(LoRaOperationTimeWatcher.MinimumAvailableTimeToCheckForCloudMessage);
if (additionalMsg != null)
{
fpending = true;
_ = loRaDevice.AbandonCloudToDeviceMessageAsync(additionalMsg);
Logger.Log(loRaDevice.DevEUI, $"found fpending c2d message id: {additionalMsg.MessageId ?? "undefined"}", LogLevel.Information);
}
}
}
}
}
}
// No C2D message and request was not confirmed, return nothing
if (!requiresConfirmation)
{
return(null);
}
var confirmDownstream = this.CreateDownlinkMessage(
cloudToDeviceMessage,
loRaDevice,
rxpk,
loraPayload,
timeWatcher,
devAddr,
fpending,
(ushort)fcntDown);
if (cloudToDeviceMessage != null)
{
if (confirmDownstream == null)
{
Logger.Log(loRaDevice.DevEUI, $"out of time for downstream message, will abandon c2d message id: {cloudToDeviceMessage.MessageId ?? "undefined"}", LogLevel.Information);
_ = loRaDevice.AbandonCloudToDeviceMessageAsync(cloudToDeviceMessage);
}
else
{
_ = loRaDevice.CompleteCloudToDeviceMessageAsync(cloudToDeviceMessage);
}
}
return(confirmDownstream);
}
}
}
