diff --git a/src/MessageHandlers/MessageHandler.cs b/src/MessageHandlers/MessageHandler.cs index d78662a..1f48145 100644 --- a/src/MessageHandlers/MessageHandler.cs +++ b/src/MessageHandlers/MessageHandler.cs @@ -37,7 +37,7 @@ public void MessageReceived(T message, MessageFormats.Common.DirectToApp fullMes case string messageType when messageType.Equals(typeof(MessageFormats.HostServices.Sensor.SensorsAvailableResponse).Name, StringComparison.CurrentCultureIgnoreCase): if (message == null) return; - _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, fullMessage.SourceAppId, (message as MessageFormats.HostServices.Sensor.SensorsAvailableResponse)?.ResponseHeader.TrackingId, (message as MessageFormats.HostServices.Sensor.SensorsAvailableResponse)?.ResponseHeader.CorrelationId); + _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, fullMessage.SourceAppId, (message as MessageFormats.HostServices.Sensor.SensorsAvailableResponse)?.ResponseHeader.TrackingId, (message as MessageFormats.HostServices.Sensor.SensorsAvailableResponse)?.ResponseHeader.CorrelationId, (message as MessageFormats.HostServices.Sensor.SensorsAvailableResponse)?.ResponseHeader.Status); if (MessageReceivedEvent == null) break; @@ -51,7 +51,7 @@ public void MessageReceived(T message, MessageFormats.Common.DirectToApp fullMes TaskingPreCheckRequestHandler(message: message as MessageFormats.HostServices.Sensor.TaskingPreCheckRequest, fullMessage: fullMessage); break; case string messageType when messageType.Equals(typeof(MessageFormats.HostServices.Sensor.TaskingPreCheckResponse).Name, StringComparison.CurrentCultureIgnoreCase): - _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, fullMessage.SourceAppId, (message as MessageFormats.HostServices.Sensor.TaskingPreCheckResponse)?.ResponseHeader.TrackingId, (message as MessageFormats.HostServices.Sensor.TaskingPreCheckResponse)?.ResponseHeader.CorrelationId); + _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, fullMessage.SourceAppId, (message as MessageFormats.HostServices.Sensor.TaskingPreCheckResponse)?.ResponseHeader.TrackingId, (message as MessageFormats.HostServices.Sensor.TaskingPreCheckResponse)?.ResponseHeader.CorrelationId, (message as MessageFormats.HostServices.Sensor.TaskingPreCheckResponse)?.ResponseHeader.Status); if (MessageReceivedEvent == null) break; @@ -64,7 +64,7 @@ public void MessageReceived(T message, MessageFormats.Common.DirectToApp fullMes TaskingRequestHandler(message: message as MessageFormats.HostServices.Sensor.TaskingRequest, fullMessage: fullMessage); break; case string messageType when messageType.Equals(typeof(MessageFormats.HostServices.Sensor.TaskingResponse).Name, StringComparison.CurrentCultureIgnoreCase): - _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, fullMessage.SourceAppId, (message as MessageFormats.HostServices.Sensor.TaskingResponse)?.ResponseHeader.TrackingId, (message as MessageFormats.HostServices.Sensor.TaskingResponse)?.ResponseHeader.CorrelationId); + _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, fullMessage.SourceAppId, (message as MessageFormats.HostServices.Sensor.TaskingResponse)?.ResponseHeader.TrackingId, (message as MessageFormats.HostServices.Sensor.TaskingResponse)?.ResponseHeader.CorrelationId, (message as MessageFormats.HostServices.Sensor.TaskingResponse)?.ResponseHeader.Status); if (MessageReceivedEvent == null) break; diff --git a/src/MessageHandlers/SensorDataHandler.cs b/src/MessageHandlers/SensorDataHandler.cs index 99bb38c..48658d4 100644 --- a/src/MessageHandlers/SensorDataHandler.cs +++ b/src/MessageHandlers/SensorDataHandler.cs @@ -8,20 +8,20 @@ private void SensorDataHandler(MessageFormats.HostServices.Sensor.SensorData? me using (var scope = _serviceProvider.CreateScope()) { DateTime maxTimeToWait = DateTime.Now.Add(TimeSpan.FromMilliseconds(_appConfig.MESSAGE_RESPONSE_TIMEOUT_MS)); - _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, fullMessage.SourceAppId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogInformation("Processing message type '{messageType}' from '{sourceApp}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, fullMessage.SourceAppId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); - _logger.LogDebug("Passing message '{messageType}' to plugins (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogDebug("Passing message '{messageType}' to plugins (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); MessageFormats.HostServices.Sensor.SensorData? pluginResult = _pluginLoader.CallPlugins( orig_request: message, pluginDelegate: _pluginDelegates.SensorData); - _logger.LogDebug("Plugins finished processing '{messageType}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogDebug("Plugins finished processing '{messageType}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); // Update the request if our plugins changed it if (pluginResult == null) { - _logger.LogInformation("Plugins nullified '{messageType}'. Dropping Message (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogInformation("Plugins nullified '{messageType}'. Dropping Message (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); return; } @@ -29,23 +29,23 @@ private void SensorDataHandler(MessageFormats.HostServices.Sensor.SensorData? me // Message is populated with the origin Tasking Tracking Id. Pull it to calculate the destination app Id if (!string.IsNullOrWhiteSpace(message.TaskingTrackingId)) { - _logger.LogDebug("Message '{messageType}' has TaskingTrackingId '{taskingTrackingId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.TaskingTrackingId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogDebug("Message '{messageType}' has TaskingTrackingId '{taskingTrackingId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, message.TaskingTrackingId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); TaskingRequest? orig_request = _client.GetCacheItem(cacheItemName: message.TaskingTrackingId).Result; if (orig_request == null) { - _logger.LogError("No TaskingTrackingId of '{taskingTrackingId}' found in cache. Unable to route message. Dropping message. (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.TaskingTrackingId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogError("No TaskingTrackingId of '{taskingTrackingId}' found in cache. Unable to route message. Dropping message. (trackingId: '{trackingId}' / correlationId: '{correlationId}'/ status: '{status}')", message.TaskingTrackingId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); return; } message.DestinationAppId = orig_request.RequestHeader.AppId; - _logger.LogDebug("Found app '{original_app_id}' for TaskingTrackingId '{taskingTrackingId}'. (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.DestinationAppId, message.TaskingTrackingId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogDebug("Found app '{original_app_id}' for TaskingTrackingId '{taskingTrackingId}'. (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.DestinationAppId, message.TaskingTrackingId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); } // No destination App ID, and no tracking ID specified. Route the message to any subscribers if (string.IsNullOrWhiteSpace(message.DestinationAppId)) { - _logger.LogTrace("Message '{messageType}' is a broadcast (message has no DestinationAppId) (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogTrace("Message '{messageType}' is a broadcast (message has no DestinationAppId) (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); // Retrieve the items from cache @@ -56,22 +56,22 @@ private void SensorDataHandler(MessageFormats.HostServices.Sensor.SensorData? me foreach (Google.Protobuf.WellKnownTypes.Value sensor_subscription in sensor_subscriptions.Values) { var list = Core.ServicesOnline(); if (Core.ServicesOnline().Any(heartbeat_pulse => heartbeat_pulse.AppId.Equals(sensor_subscription.StringValue, StringComparison.InvariantCultureIgnoreCase))) { - _logger.LogInformation("Sending message '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, sensor_subscription.StringValue, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogInformation("Sending message '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, sensor_subscription.StringValue, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); _client.DirectToApp(appId: sensor_subscription.StringValue, message: message).Wait(); } else { - _logger.LogError("Unable to route message '{messageType}'. '{appId}' is not online. (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, sensor_subscription.StringValue, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogError("Unable to route message '{messageType}'. '{appId}' is not online. (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, sensor_subscription.StringValue, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); } } } } else { // Original app ID is online. Send the message and then end cleanly if (Core.ServicesOnline().Any(heartbeat_pulse => heartbeat_pulse.AppId.Equals(message.DestinationAppId, StringComparison.InvariantCultureIgnoreCase))) { - _logger.LogInformation("Sending message '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.DestinationAppId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogInformation("Sending message '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, message.DestinationAppId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); // Append the sensor ID for topic suffix so we can authZ the response going back to the app _client.DirectToApp(appId: message.DestinationAppId, message: message).Wait(); } else { - _logger.LogError("Unable to route message '{messageType}'. '{appId}' is not online. (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.DestinationAppId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId); + _logger.LogError("Unable to route message '{messageType}'. '{appId}' is not online. (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, message.DestinationAppId, message.ResponseHeader.TrackingId, message.ResponseHeader.CorrelationId, message.ResponseHeader.Status); } } }; diff --git a/src/MessageHandlers/SensorsAvailableRequestHandler.cs b/src/MessageHandlers/SensorsAvailableRequestHandler.cs index 59b2972..5d8f555 100644 --- a/src/MessageHandlers/SensorsAvailableRequestHandler.cs +++ b/src/MessageHandlers/SensorsAvailableRequestHandler.cs @@ -87,20 +87,20 @@ void SensorsAvailableResponseCallback(object? sender, MessageFormats.HostService return; } - _logger.LogInformation("Response to request message type '{messageType}' is '{returnResponseStatus}' (Response Message is '{returnResponseMessage}') (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogInformation("Response to request message type '{messageType}' is '{returnResponseStatus}' (Response Message is '{returnResponseMessage}') (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); if (returnResponse.ResponseHeader.Status == MessageFormats.Common.StatusCodes.Successful) { _logger.LogTrace("Caching '{messageType}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); _client.SaveCacheItem(cacheItem: message, cacheItemName: message.RequestHeader.TrackingId, expiration: DateTime.UtcNow.AddMinutes(15)).Wait(); } else { - _logger.LogWarning("Unable to process '{messageType}'. Response Status is '{returnResponseStatus}'. Response Message is '{returnResponseMessage}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogWarning("Unable to process '{messageType}'. Response Status is '{returnResponseStatus}'. Response Message is '{returnResponseMessage}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); } returnResponse = output_response; message = output_request; - _logger.LogInformation("Routing message type '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", returnResponse.GetType().Name, fullMessage.SourceAppId, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogInformation("Routing message type '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", returnResponse.GetType().Name, fullMessage.SourceAppId, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); _client.DirectToApp(appId: fullMessage.SourceAppId, message: returnResponse); }; } diff --git a/src/MessageHandlers/TaskingPreCheckRequestHandler.cs b/src/MessageHandlers/TaskingPreCheckRequestHandler.cs index 674df5f..5af6d68 100644 --- a/src/MessageHandlers/TaskingPreCheckRequestHandler.cs +++ b/src/MessageHandlers/TaskingPreCheckRequestHandler.cs @@ -85,20 +85,20 @@ void TaskingPreCheckResponseCallback(object? sender, MessageFormats.HostServices return; } - _logger.LogInformation("Response to request message type '{messageType}' is '{returnResponseStatus}' (Response Message is '{returnResponseMessage}') (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogInformation("Response to request message type '{messageType}' is '{returnResponseStatus}' (Response Message is '{returnResponseMessage}') (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); if (returnResponse.ResponseHeader.Status == MessageFormats.Common.StatusCodes.Successful) { _logger.LogTrace("Caching '{messageType}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); _client.SaveCacheItem(cacheItem: message, cacheItemName: message.RequestHeader.TrackingId, expiration: DateTime.UtcNow.AddMinutes(15)).Wait(); } else { - _logger.LogWarning("Unable to process '{messageType}'. Response Status is '{returnResponseStatus}'. Response Message is '{returnResponseMessage}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogWarning("Unable to process '{messageType}'. Response Status is '{returnResponseStatus}'. Response Message is '{returnResponseMessage}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); } returnResponse = output_response; message = output_request; - _logger.LogInformation("Routing message type '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", returnResponse.GetType().Name, fullMessage.SourceAppId, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogInformation("Routing message type '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", returnResponse.GetType().Name, fullMessage.SourceAppId, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); _client.DirectToApp(appId: fullMessage.SourceAppId, message: returnResponse); }; } diff --git a/src/MessageHandlers/TaskingRequestHandler.cs b/src/MessageHandlers/TaskingRequestHandler.cs index d30e984..7f33f7c 100644 --- a/src/MessageHandlers/TaskingRequestHandler.cs +++ b/src/MessageHandlers/TaskingRequestHandler.cs @@ -88,20 +88,20 @@ void TaskingResponseCallback(object? sender, MessageFormats.HostServices.Sensor. return; } - _logger.LogInformation("Response to request message type '{messageType}' is '{returnResponseStatus}' (Response Message is '{returnResponseMessage}') (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogInformation("Response to request message type '{messageType}' is '{returnResponseStatus}' (Response Message is '{returnResponseMessage}') (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); if (returnResponse.ResponseHeader.Status == MessageFormats.Common.StatusCodes.Successful) { _logger.LogTrace("Caching '{messageType}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); _client.SaveCacheItem(cacheItem: message, cacheItemName: message.RequestHeader.TrackingId, expiration: DateTime.UtcNow.AddMinutes(15)).Wait(); } else { - _logger.LogWarning("Unable to process '{messageType}'. Response Status is '{returnResponseStatus}'. Response Message is '{returnResponseMessage}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogWarning("Unable to process '{messageType}'. Response Status is '{returnResponseStatus}'. Response Message is '{returnResponseMessage}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", message.GetType().Name, returnResponse.ResponseHeader.Status, returnResponse.ResponseHeader.Message, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); } returnResponse = output_response; message = output_request; - _logger.LogInformation("Routing message type '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}')", returnResponse.GetType().Name, fullMessage.SourceAppId, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId); + _logger.LogInformation("Routing message type '{messageType}' to '{appId}' (trackingId: '{trackingId}' / correlationId: '{correlationId}' / status: '{status}')", returnResponse.GetType().Name, fullMessage.SourceAppId, message.RequestHeader.TrackingId, message.RequestHeader.CorrelationId, returnResponse.ResponseHeader.Status); UpdateSensorBroadcastResults(taskingRequest: message, taskingResponse: returnResponse, fullMessage: fullMessage); _client.DirectToApp(appId: fullMessage.SourceAppId, message: returnResponse); };