From bc217a200806e1c59e599a40ec6a6ff4562b34af Mon Sep 17 00:00:00 2001 From: Andrew Welker Date: Mon, 8 Jul 2024 08:44:45 -0500 Subject: [PATCH] chore: add logging for current scenario searching --- .../Room/Combining/EssentialsRoomCombiner.cs | 39 +++++++++++-------- .../Room/Combining/RoomCombinationScenario.cs | 23 +++++------ .../Routing/Extensions.cs | 21 ++++++---- .../Routing/RouteRequest.cs | 8 +++- 4 files changed, 52 insertions(+), 39 deletions(-) diff --git a/src/PepperDash.Essentials.Core/Room/Combining/EssentialsRoomCombiner.cs b/src/PepperDash.Essentials.Core/Room/Combining/EssentialsRoomCombiner.cs index 21cc332ff..df50e864e 100644 --- a/src/PepperDash.Essentials.Core/Room/Combining/EssentialsRoomCombiner.cs +++ b/src/PepperDash.Essentials.Core/Room/Combining/EssentialsRoomCombiner.cs @@ -1,11 +1,10 @@ -using System; -using System.Collections.Generic; -using System.Linq; -using Crestron.SimplSharp; - +using Crestron.SimplSharp; using PepperDash.Core; +using PepperDash.Core.Logging; using Serilog.Events; -using Newtonsoft.Json; +using System; +using System.Collections.Generic; +using System.Linq; namespace PepperDash.Essentials.Core { @@ -35,7 +34,7 @@ public bool IsInAutoMode } set { - if(value == _isInAutoMode) + if (value == _isInAutoMode) { return; } @@ -93,7 +92,7 @@ public EssentialsRoomCombiner(string key, EssentialsRoomCombinerPropertiesConfig }); } - void CreateScenarios() + private void CreateScenarios() { foreach (var scenarioConfig in _propertiesConfig.Scenarios) { @@ -102,21 +101,20 @@ void CreateScenarios() } } - void SetRooms() + private void SetRooms() { _rooms = new List(); foreach (var roomKey in _propertiesConfig.RoomKeys) { - var room = DeviceManager.GetDeviceForKey(roomKey) as IEssentialsRoom; - if (room != null) + if (DeviceManager.GetDeviceForKey(roomKey) is IEssentialsRoom room) { _rooms.Add(room); } } } - void SetupPartitionStateProviders() + private void SetupPartitionStateProviders() { foreach (var pConfig in _propertiesConfig.Partitions) { @@ -130,18 +128,18 @@ void SetupPartitionStateProviders() } } - void PartitionPresentFeedback_OutputChange(object sender, FeedbackEventArgs e) + private void PartitionPresentFeedback_OutputChange(object sender, FeedbackEventArgs e) { StartDebounceTimer(); } - void StartDebounceTimer() + private void StartDebounceTimer() { // default to 500ms for manual mode var time = 500; // if in auto mode, debounce the scenario change - if(IsInAutoMode) time = _scenarioChangeDebounceTimeSeconds * 1000; + if (IsInAutoMode) time = _scenarioChangeDebounceTimeSeconds * 1000; if (_scenarioChangeDebounceTimer == null) { @@ -156,7 +154,7 @@ void StartDebounceTimer() /// /// Determines the current room combination scenario based on the state of the partition sensors /// - void DetermineRoomCombinationScenario() + private void DetermineRoomCombinationScenario() { if (_scenarioChangeDebounceTimer != null) { @@ -164,14 +162,20 @@ void DetermineRoomCombinationScenario() _scenarioChangeDebounceTimer = null; } + this.LogInformation("Determining Combination Scenario"); + var currentScenario = RoomCombinationScenarios.FirstOrDefault((s) => { + this.LogDebug("Checking scenario {scenarioKey}", s.Key); // iterate the partition states foreach (var partitionState in s.PartitionStates) { + this.LogDebug("checking PartitionState {partitionStateKey}", partitionState.PartitionKey); // get the partition by key var partition = Partitions.FirstOrDefault((p) => p.Key.Equals(partitionState.PartitionKey)); + this.LogDebug("Expected State: {partitionPresent} Actual State: {partitionState}", partitionState.PartitionPresent, partition.PartitionPresentFeedback.BoolValue); + if (partition != null && partitionState.PartitionPresent != partition.PartitionPresentFeedback.BoolValue) { // the partition can't be found or the state doesn't match @@ -184,6 +188,7 @@ void DetermineRoomCombinationScenario() if (currentScenario != null) { + this.LogInformation("Found combination Scenario {scenarioKey}", currentScenario.Key); CurrentScenario = currentScenario; } } @@ -253,7 +258,7 @@ public void SetManualMode() public void ToggleMode() { - if(IsInAutoMode) + if (IsInAutoMode) { SetManualMode(); } diff --git a/src/PepperDash.Essentials.Core/Room/Combining/RoomCombinationScenario.cs b/src/PepperDash.Essentials.Core/Room/Combining/RoomCombinationScenario.cs index 9bc0d8ec3..84674d021 100644 --- a/src/PepperDash.Essentials.Core/Room/Combining/RoomCombinationScenario.cs +++ b/src/PepperDash.Essentials.Core/Room/Combining/RoomCombinationScenario.cs @@ -1,22 +1,15 @@ - - -using System; -using System.Collections.Generic; -using System.Linq; -using System.Text; -using Crestron.SimplSharp; - +using Newtonsoft.Json; using PepperDash.Core; - -using Newtonsoft.Json; +using PepperDash.Core.Logging; using Serilog.Events; +using System.Collections.Generic; namespace PepperDash.Essentials.Core { /// /// Represents a room combination scenario /// - public class RoomCombinationScenario: IRoomCombinationScenario, IKeyName + public class RoomCombinationScenario : IRoomCombinationScenario, IKeyName { private RoomCombinationScenarioConfig _config; @@ -40,7 +33,7 @@ public bool IsActive get { return _isActive; } set { - if(value == _isActive) + if (value == _isActive) { return; } @@ -78,12 +71,13 @@ public RoomCombinationScenario(RoomCombinationScenarioConfig config) public void Activate() { - Debug.LogMessage(LogEventLevel.Debug, "Activating Scenario: '{0}' with {1} action(s) defined", Name, activationActions.Count); + Debug.LogMessage(LogEventLevel.Debug, "Activating Scenario: '{name}' with {activationActionCount} action(s) defined", this, Name, activationActions.Count); if (activationActions != null) { foreach (var action in activationActions) { + this.LogDebug("Running Activation action {@action}", action); DeviceJsonApi.DoDeviceAction(action); } } @@ -93,12 +87,13 @@ public void Activate() public void Deactivate() { - Debug.LogMessage(LogEventLevel.Debug, "Deactivating Scenario: '{0}' with {1} action(s) defined", Name, deactivationActions.Count); + Debug.LogMessage(LogEventLevel.Debug, "Deactivating Scenario: '{name}' with {deactivationActionCount} action(s) defined", this, Name, deactivationActions.Count); if (deactivationActions != null) { foreach (var action in deactivationActions) { + this.LogDebug("Running deactivation action {@action}", action); DeviceJsonApi.DoDeviceAction(action); } } diff --git a/src/PepperDash.Essentials.Core/Routing/Extensions.cs b/src/PepperDash.Essentials.Core/Routing/Extensions.cs index a0eba868b..b612796a5 100644 --- a/src/PepperDash.Essentials.Core/Routing/Extensions.cs +++ b/src/PepperDash.Essentials.Core/Routing/Extensions.cs @@ -1,8 +1,10 @@ -using PepperDash.Core; -using Serilog.Events; +using Serilog.Events; using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; +using System.Runtime.CompilerServices; +using Debug = PepperDash.Core.Debug; namespace PepperDash.Essentials.Core @@ -21,8 +23,13 @@ public static class Extensions /// and then attempts a new Route and if sucessful, stores that RouteDescriptor /// in RouteDescriptorCollection.DefaultCollection /// + [MethodImpl(MethodImplOptions.NoInlining)] // REMOVE ME public static void ReleaseAndMakeRoute(this IRoutingInputs destination, IRoutingOutputs source, eRoutingSignalType signalType, string destinationPortKey = "", string sourcePortKey = "") { + // Remove this line before committing!!!!! + var frame = new StackFrame(1, true); + Debug.LogMessage(LogEventLevel.Information, "ReleaseAndMakeRoute Called from {method} with params {destinationKey}:{sourceKey}:{signalType}:{destinationPortKey}:{sourcePortKey}", frame.GetMethod().Name, destination.Key, source.Key, signalType.ToString(), destinationPortKey, sourcePortKey); + var inputPort = string.IsNullOrEmpty(destinationPortKey) ? null : destination.InputPorts.FirstOrDefault(p => p.Key == destinationPortKey); var outputPort = string.IsNullOrEmpty(sourcePortKey) ? null : source.OutputPorts.FirstOrDefault(p => p.Key == sourcePortKey); @@ -33,8 +40,8 @@ private static void ReleaseAndMakeRoute(IRoutingInputs destination, IRoutingOutp { if (destination == null) throw new ArgumentNullException(nameof(destination)); if (source == null) throw new ArgumentNullException(nameof(source)); - if (destinationPort == null) Debug.LogMessage(LogEventLevel.Verbose, "Destination port is null"); - if (sourcePort == null) Debug.LogMessage(LogEventLevel.Verbose, "Source port is null"); + if (destinationPort == null) Debug.LogMessage(LogEventLevel.Information, "Destination port is null"); + if (sourcePort == null) Debug.LogMessage(LogEventLevel.Information, "Source port is null"); var routeRequest = new RouteRequest { @@ -57,7 +64,7 @@ private static void ReleaseAndMakeRoute(IRoutingInputs destination, IRoutingOutp RouteRequests[destination.Key] = routeRequest; - Debug.LogMessage(LogEventLevel.Verbose, "Device: {0} is cooling down and already has a routing request stored. Storing new route request to route to source key: {1}", null, destination.Key, routeRequest.Source.Key); + Debug.LogMessage(LogEventLevel.Information, "Device: {destination} is cooling down and already has a routing request stored. Storing new route request to route to source key: {sourceKey}", null, destination.Key, routeRequest.Source.Key); return; } @@ -71,14 +78,14 @@ private static void ReleaseAndMakeRoute(IRoutingInputs destination, IRoutingOutp RouteRequests.Add(destination.Key, routeRequest); - Debug.LogMessage(LogEventLevel.Verbose, "Device: {0} is cooling down. Storing route request to route to source key: {1}", null, destination.Key, routeRequest.Source.Key); + Debug.LogMessage(LogEventLevel.Information, "Device: {destination} is cooling down. Storing route request to route to source key: {sourceKey}", null, destination.Key, routeRequest.Source.Key); return; } if (RouteRequests.ContainsKey(destination.Key) && coolingDevice != null && coolingDevice.IsCoolingDownFeedback.BoolValue == false) { RouteRequests.Remove(destination.Key); - Debug.LogMessage(LogEventLevel.Verbose, "Device: {0} is NOT cooling down. Removing stored route request and routing to source key: {1}", null, destination.Key, routeRequest.Source.Key); + Debug.LogMessage(LogEventLevel.Information, "Device: {destination} is NOT cooling down. Removing stored route request and routing to source key: {sourceKey}", null, destination.Key, routeRequest.Source.Key); } destination.ReleaseRoute(); diff --git a/src/PepperDash.Essentials.Core/Routing/RouteRequest.cs b/src/PepperDash.Essentials.Core/Routing/RouteRequest.cs index 351694747..02b7ff3c6 100644 --- a/src/PepperDash.Essentials.Core/Routing/RouteRequest.cs +++ b/src/PepperDash.Essentials.Core/Routing/RouteRequest.cs @@ -1,4 +1,7 @@ -namespace PepperDash.Essentials.Core +using PepperDash.Core; +using Serilog.Events; + +namespace PepperDash.Essentials.Core { public class RouteRequest { @@ -11,10 +14,13 @@ public class RouteRequest public void HandleCooldown(object sender, FeedbackEventArgs args) { + Debug.LogMessage(LogEventLevel.Information, "Handling cooldown route request: {destination}:{destinationPort} -> {source}:{sourcePort} {type}", null, Destination.Key, DestinationPort.Key, Source.Key, SourcePort.Key, SignalType.ToString()); + var coolingDevice = sender as IWarmingCooling; if (args.BoolValue == false) { + Debug.LogMessage(LogEventLevel.Information, "Cooldown complete. Making route from {destination} to {source}", Destination.Key, Source.Key); Destination.ReleaseAndMakeRoute(Source, SignalType); if (sender == null) return;