private async Task ProcessMessage(EventData eventData, long partitionKey, RbTraceLog rbTraceLog)
{
// Receive a message and system properties
string iothub_deviceId = (string)eventData.SystemProperties["iothub-connection-device-id"];
DateTime iothub_enqueuedTimeUtc = (DateTime)eventData.SystemProperties.EnqueuedTimeUtc;
string text_message = Encoding.UTF8.GetString(eventData.Body.Array);
// RbTrace (Table Storage)
if (rbTraceLevel == RbTraceType.Detail)
{
rbTraceLog.WriteLog($"Received a message. Partition({partitionKey}), DeviceId({iothub_deviceId}), Message:{text_message}");
}
// Loop of retry for reconfiguration on SQL Database
int loopCounter = 0;
while (true)
{
JObject jo_message = null;
// Routing switch
bool devRouting = false;
bool appRouting = false;
try
{
// Check RbHeader
if (text_message.IndexOf(RbFormatType.RbHeader) < 0)
{
rbTraceLog.WriteLog(RbExceptionMessage.RbHeaderNotFound
+ $" Partition({partitionKey}), DeviceId({iothub_deviceId}), Message:{text_message}");
return;
}
// Check RbHeader simplly
jo_message = JsonConvert.DeserializeObject <JObject>(text_message);
var jo_rbh = (JObject)jo_message[RbFormatType.RbHeader];
var v_rbhRoutingType = jo_rbh[RbHeaderElement.RoutingType];
if (v_rbhRoutingType == null)
{
rbTraceLog.WriteError("W001", "** Message skipped because RoutingType is null **", jo_message);
return;
}
string s_rbhRoutingType = (string)v_rbhRoutingType;
if (s_rbhRoutingType == RbRoutingType.LOG || s_rbhRoutingType == string.Empty)
{
// RoutingType == LOG -> only using IoT Hub with Stream Analytics
return;
}
// Check RbHeader in detail
RbHeaderBuilder hdBuilder = new RbHeaderBuilder(jo_message, iothub_deviceId);
RbHeader rbh = null;
try
{
rbh = hdBuilder.ValidateJsonSchema();
}
catch (Exception ex)
{
rbTraceLog.WriteError("W002", "** Message skipped because of bad RbHeader **", ex);
return;
}
// Check StorageQueueSendEnabled property in RbHeader
prevStorageQueueSendEnabled = storageQueueSendEnabled;
string messageStorageQueueSendEnabled = null;
if (storageQueueSendEnabled != "true")
{
try
{
messageStorageQueueSendEnabled = (string)jo_rbh[typeStorageQueueSendEnabled];
}
catch
{
messageStorageQueueSendEnabled = null;
}
if (messageStorageQueueSendEnabled == "true")
{
storageQueueSendEnabled = messageStorageQueueSendEnabled;
}
}
// Check RoutingType (CALL, D2D, CONTROL)
if (rbh.RoutingType == RbRoutingType.CALL || rbh.RoutingType == RbRoutingType.CALL_ASYNC)
{
appRouting = true;
}
else if (rbh.RoutingType == RbRoutingType.D2D)
{
devRouting = true;
if (rbh.AppProcessingId != string.Empty)
{
appRouting = true;
}
}
else if (rbh.RoutingType == RbRoutingType.CONTROL)
{
devRouting = false;
appRouting = false;
}
else
{
rbTraceLog.WriteError("W003", "** Message skipped because of bad RoutingType **", jo_message);
return;
}
// Device Router builds RbHeader
DeviceRouter dr = null;
if (devRouting)
{
dr = new DeviceRouter(rbh, sqlConnectionString);
rbh = dr.GetDeviceRouting();
string new_header = JsonConvert.SerializeObject(rbh);
jo_message[RbFormatType.RbHeader] = JsonConvert.DeserializeObject <JObject>(new_header);
}
else
{
rbh.TargetDeviceId = rbh.SourceDeviceId;
rbh.TargetType = RbTargetType.Device;
}
// Application Routing
JArray ja_messages = null;
if (appRouting)
{
// Application Call Logic
JObject jo_temp;
string rbBodyString;
try
{
jo_temp = (JObject)jo_message[RbFormatType.RbBody];
rbBodyString = JsonConvert.SerializeObject(jo_temp);
}
catch (Exception ex)
{
rbTraceLog.WriteError("E001", $"** RbBody is not regular JSON format ** {ex.ToString()}", jo_message);
return;
}
try
{
if (rbh.RoutingType == RbRoutingType.CALL_ASYNC)
{
await CallAppsWithQueue(rbh, rbBodyString, partitionKey.ToString());
}
else
{
ja_messages = await CallAppsWithHttp(rbh, rbBodyString, partitionKey.ToString());
}
}
catch (Exception ex)
{
rbTraceLog.WriteError("E002", $"** Error occured in CallApps ** {ex.ToString()}", jo_message);
return;
}
}
else
{
ja_messages = new JArray();
ja_messages.Add(jo_message);
}
// Send C2D Message
if (rbh.RoutingType == RbRoutingType.CALL ||
rbh.RoutingType == RbRoutingType.D2D ||
rbh.RoutingType == RbRoutingType.CONTROL)
{
if (storageQueueSendEnabled == "true")
{
// Send C2D message to Queue storage
RbC2dMessageToQueue c2dsender = null;
c2dsender = new RbC2dMessageToQueue(ja_messages, storageQueueConnString, sqlConnectionString);
await c2dsender.SendToDeviceAsync();
}
else
{
// Send C2D message to IoT Hub
RbC2dMessageSender c2dsender = null;
c2dsender = new RbC2dMessageSender(ja_messages, iotHubConnectionString, sqlConnectionString);
await c2dsender.SendToDeviceAsync();
}
// StorageQueueSendEnabled property in RbHeader
storageQueueSendEnabled = prevStorageQueueSendEnabled;
}
// Get out of retry loop because of normal completion
break;
}
catch (Exception ex)
{
rbTraceLog.WriteError("E003", $"** Critical error occured ** {ex.ToString()}", jo_message);
bool continueLoop = false;
if (ex != null && ex is SqlException)
{
foreach (SqlError error in (ex as SqlException).Errors)
{
if (sqlErrorListForRetry.Contains(error.Number))
{
continueLoop = true;
break; // Exit foreach loop
}
}
if (continueLoop)
{
++loopCounter;
rbTraceLog.WriteLog($"Transaction retry has started. Count({loopCounter})");
if (loopCounter > maxLoopCounter)
{
break; // Get out of retry loop because counter reached max number
}
else
{
Thread.Sleep(sleepInterval);
}
}
else
{
break; // Get out of retry loop because of another sql error
}
}
else
{
throw;
}
}
}
}
async Task IEventProcessor.ProcessEventsAsync(PartitionContext context, IEnumerable <EventData> messages)
{
try
{
#region *** Handling unexpected exceptions ***
DateTime startDateTimeUtc = DateTime.UtcNow;
int messagecnt = 0;
bool sqlex_on = false;
foreach (EventData eventData in messages)
{
try
{
// Go forward read pointer
await context.CheckpointAsync();
}
catch (Exception ex)
{
// Handling the exception of Microsoft.ServiceBus.Messaging.LeaseLostException
// This exception is usually able to occur.
ApplicationException ae = new ApplicationException(checkpointExMessage, ex);
throw ae;
}
++messagecnt;
int retryCount = 0;
bool devRouting = false;
bool appRouting = false;
bool rbHeaderNotFound = false;
string sqlConnString = rbSqlConnectionString;
string iothub_deviceId = (string)eventData.SystemProperties["iothub-connection-device-id"];
DateTime iothub_enqueuedTimeUtc = (DateTime)eventData.SystemProperties["EnqueuedTimeUtc"];
string text_message = string.Empty;
// Retry loop logic for SQLDB reconfiguration exception
while (true)
{
text_message = Encoding.UTF8.GetString(eventData.GetBytes());
string text_message_100 = text_message.Substring(0, 100);
if (text_message_100.IndexOf(RbFormatType.RbHeader) < 0)
{
rbHeaderNotFound = true;
RbTraceLog.WriteLog(string.Format(RbExceptionMessage.RbHeaderNotFound + " Partition:{0}, Message:{1}, DeviceId:{2}",
context.Lease.PartitionId, text_message_100, iothub_deviceId));
}
if (rbTraceLevel == RbTraceType.Detail)
{
DateTime dt = iothub_enqueuedTimeUtc;
TimeSpan ts = DateTime.UtcNow - dt;
RbTraceLog.WriteLog(string.Format("RoboticsEventProcessor Message received. Delayed time:{0}, Partition:{1}, DeviceId:{2}, Message:{3}",
ts.ToString(), context.Lease.PartitionId, iothub_deviceId, text_message));
if (ts > new TimeSpan(0, 0, 5))
{
RbTraceLog.WriteLog(string.Format("** Delayed time is over 5 seconds !! ** DelayedTime:{0}, Partition:{1}, DeviceId:{2}, Message:{3}",
ts.ToString(), context.Lease.PartitionId, iothub_deviceId, text_message));
}
}
JObject jo_message = null;
if (!rbHeaderNotFound) // Skip invalid data
{
try
{
jo_message = JsonConvert.DeserializeObject <JObject>(text_message);
// Check RbHeader simplly
var jo_rbh = (JObject)jo_message[RbFormatType.RbHeader];
if (jo_rbh != null)
{
string jo_rbh_RoutingType = (string)jo_rbh[RbHeaderElement.RoutingType];
// Check RoutingType (LOG, null)
if (jo_rbh_RoutingType == null)
{
RbTraceLog.WriteError("W001", "** Message skipped because RoutingType is null **", jo_message);
goto LoopExitLabel;
}
else if (jo_rbh_RoutingType == RbRoutingType.LOG)
{
// RoutingType == LOG -> only using IoT Hub with Stream Analytics
goto LoopExitLabel;
}
}
// Check RbHeader in detail
RbHeaderBuilder hdBuilder = new RbHeaderBuilder(jo_message, iothub_deviceId);
RbHeader rbh = hdBuilder.ValidateJsonSchema();
// Check RoutingType (CALL, D2D, CONTROL)
if (rbh.RoutingType == RbRoutingType.CALL)
{
appRouting = true;
}
else if (rbh.RoutingType == RbRoutingType.D2D)
{
devRouting = true;
if (rbh.AppProcessingId != string.Empty)
{
appRouting = true;
}
}
else if (rbh.RoutingType == RbRoutingType.CONTROL)
{
devRouting = false;
appRouting = false;
}
else
{
RbTraceLog.WriteError("W002", "** Message skipped because of bad RoutingType **", jo_message);
goto LoopExitLabel;
}
// Device Router builds RbHeader
DeviceRouter dr = null;
if (devRouting)
{
dr = new DeviceRouter(rbh, sqlConnString);
rbh = dr.GetDeviceRouting();
string new_header = JsonConvert.SerializeObject(rbh);
jo_message[RbFormatType.RbHeader] = JsonConvert.DeserializeObject <JObject>(new_header);
}
else
{
rbh.TargetDeviceId = rbh.SourceDeviceId;
rbh.TargetType = RbTargetType.Device;
}
// Application Routing
JArray ja_messages = null;
if (appRouting)
{
// Application Call Logic
JObject jo_temp = (JObject)jo_message[RbFormatType.RbBody];
string rbBodyString = JsonConvert.SerializeObject(jo_temp);
ja_messages = CallApps(rbh, rbBodyString, context.Lease.PartitionId);
}
else if (rbh.RoutingType != RbRoutingType.CONTROL)
{
ja_messages = new JArray();
ja_messages.Add(jo_message);
}
// RoutingType="CONTROL" and AppProcessingId="ReqAppInfo"
if (rbh.RoutingType == RbRoutingType.CONTROL)
{
if (rbh.AppProcessingId == null)
{
RbTraceLog.WriteError("W003", "** Message skipped because AppProcessingId is null when CONTROL RoutingType **", jo_message);
goto LoopExitLabel;
}
else if (rbh.AppProcessingId == RbControlType.ReqAppInfo)
{
ja_messages = ProcessControlMessage(rbh);
}
else
{
RbTraceLog.WriteError("W004", "** Message skipped because of bad AppProcessingId when CONTROL RoutingType **", jo_message);
goto LoopExitLabel;
}
}
// Send C2D Message
if (rbh.RoutingType == RbRoutingType.CALL ||
rbh.RoutingType == RbRoutingType.D2D ||
rbh.RoutingType == RbRoutingType.CONTROL)
{
if (rbStorageQueueSendEnabled)
{
// Send C2D message to Queue storage
RbC2dMessageToQueue c2dsender = null;
c2dsender = new RbC2dMessageToQueue(ja_messages, rbStorageQueueConnString, sqlConnString);
c2dsender.SendToDevice();
}
else
{
// Send C2D message to IoT Hub
RbC2dMessageSender c2dsender = null;
c2dsender = new RbC2dMessageSender(ja_messages, rbIotHubConnString, sqlConnString);
c2dsender.SendToDevice();
}
}
// C2D Message Logging to Event Hub
if (rbC2dLogEnabled)
{
RbEventHubs rbEventHubs = new RbEventHubs(rbC2dLogEventHubConnString, rbC2dLogEventHubName);
foreach (JObject jo in ja_messages)
{
string str_message = JsonConvert.SerializeObject(jo);
rbEventHubs.SendMessage(str_message, iothub_deviceId);
}
}
}
catch (Exception ex)
{
sqlex_on = false;
if (ex != null && ex is SqlException) // "is" matches extended type as well
{
foreach (SqlError error in (ex as SqlException).Errors)
{
if (sqlErrorListForRetry.Contains(error.Number))
{
sqlex_on = true;
break; // Exit foreach loop
}
}
if (sqlex_on)
{
++retryCount;
if (retryCount > maxRetryCount)
{
sqlex_on = false;
RbTraceLog.WriteError("E001", ex.ToString(), jo_message);
}
else
{
RbTraceLog.WriteLog($"Transaction retry has started. Count({retryCount})");
Thread.Sleep(sleepTime);
}
}
else
{
RbTraceLog.WriteError("E001", ex.ToString(), jo_message);
}
}
else
{
RbTraceLog.WriteError("E001", ex.ToString(), jo_message);
}
}
}
if (!sqlex_on)
{
goto LoopExitLabel;
}
}
// Label - Loop exit
LoopExitLabel :;
if (rbTraceLevel == RbTraceType.Detail)
{
TimeSpan ts = DateTime.UtcNow - startDateTimeUtc;
RbTraceLog.WriteLog(string.Format("RoboticsEventProcessor Message processed. Duration:{0}, Partition:{1}, DeviceId{2}, Message:{3}",
ts.ToString(), context.Lease.PartitionId, iothub_deviceId, text_message));
}
}
#endregion *** Handling unexpected exceptions ***
}
catch (Exception ex)
{
if (ex.Message == checkpointExMessage)
{
RbTraceLog.WriteLog("** Retrying message processing because of CheckPointAsync error ** Info => "
+ ex.InnerException.ToString());
}
else
{
RbTraceLog.WriteError("E999", ex.ToString());
}
}
}