diff --git a/Zetbox.Workflow.Common/Workflow/ActionActions.cs b/Zetbox.Workflow.Common/Workflow/ActionActions.cs index a704228..a0b9614 100644 --- a/Zetbox.Workflow.Common/Workflow/ActionActions.cs +++ b/Zetbox.Workflow.Common/Workflow/ActionActions.cs @@ -9,6 +9,7 @@ namespace Zetbox.Basic.Workflow using Zetbox.API; using Zetbox.API.Common; using Zetbox.App.Base; + using Zetbox.API.Utils; /// @@ -56,12 +57,16 @@ public static void Execute(Action obj, ParameterizedActionDefinition paramedActi if (current == null) throw new ArgumentException("current"); var identity = _idResolver.GetCurrent(); + Logging.Log.InfoFormat("Executing workflow action [{0}].{1}", current, obj.Name); + // call invocation if (_invocationExec.HasValidInvocation(obj)) { + Logging.Log.DebugFormat(" calling invocation [{0}].{1}", obj.ImplementorName, obj.MemberName); var result = _invocationExec.CallInvocation(obj, typeof(ActionInvocationPrototype), obj, paramedAction, current, identity); if (result == false) { + Logging.Log.Info(" -> returned false, exiting"); return; } } diff --git a/Zetbox.Workflow.Common/Workflow/StateActions.cs b/Zetbox.Workflow.Common/Workflow/StateActions.cs index eba1dea..fc9ef5a 100644 --- a/Zetbox.Workflow.Common/Workflow/StateActions.cs +++ b/Zetbox.Workflow.Common/Workflow/StateActions.cs @@ -4,6 +4,7 @@ using System.Text; using Zetbox.API; using Zetbox.App.Base; +using Zetbox.API.Utils; namespace Zetbox.Basic.Workflow { @@ -12,6 +13,8 @@ public static class StateActions { internal static State CreateState(WFInstance instance, StateDefinition def) { + Logging.Log.InfoFormat("Creating WorkflowState [{0}].{1}", instance, def.Name); + var ctx = instance.Context; var state = ctx.Create(); state.Instance = instance; @@ -45,6 +48,7 @@ public static void postSet_LeftOn(State obj, PropertyPostSetterEventArgs /// An state change invocation prototype. If nothing changes, return StateChange.NextStates. If the state should end, return null or empty. If specific states should be entered, return them. @@ -65,17 +66,23 @@ public static void Execute(StateChangeDefinition obj, Zetbox.Basic.Workflow.Stat { var identity = _idResolver.GetCurrent(); + Logging.Log.InfoFormat("Executing workflow StateChange [{0}].{1}", current, obj.Name); + var nextStates = obj.NextStates.ToList(); // call invocation if (_invocationExec.HasValidInvocation(obj)) { + Logging.Log.DebugFormat(" calling invocation [{0}].{1}", obj.ImplementorName, obj.MemberName); nextStates = _invocationExec.CallInvocation>(obj, typeof(StateChangeInvocationPrototype), obj, current, identity); } + Logging.Log.InfoFormat(" nextStates.Count = {0}", nextStates.Count); + var stateEnds = true; if (nextStates == null || nextStates.Count == 0) { // workflow branch ends here + Logging.Log.Info("No next states, workflow will end"); } else { @@ -84,6 +91,7 @@ public static void Execute(StateChangeDefinition obj, Zetbox.Basic.Workflow.Stat { if (stateDef == current.StateDefinition) { + Logging.Log.Info("Staying in current state"); stateEnds = false; } else diff --git a/Zetbox.Workflow.Common/Workflow/WFInstanceActions.cs b/Zetbox.Workflow.Common/Workflow/WFInstanceActions.cs index 263b656..fbf6d90 100644 --- a/Zetbox.Workflow.Common/Workflow/WFInstanceActions.cs +++ b/Zetbox.Workflow.Common/Workflow/WFInstanceActions.cs @@ -8,6 +8,7 @@ namespace Zetbox.Basic.Workflow using Zetbox.API; using Zetbox.API.Common; using Zetbox.App.Base; + using Zetbox.API.Utils; [Implementor] public class WFInstanceActions @@ -42,6 +43,7 @@ public static void Start(WFInstance obj, Zetbox.Basic.Workflow.WFDefinition work { if (workflow != null) { + Logging.Log.InfoFormat("Starting workflow {0}", workflow.Name); obj.Workflow = workflow; foreach (var stateDef in workflow.StateDefinitions.Where(s => s.IsStartState)) { @@ -85,6 +87,7 @@ public static void AddLogEntry(WFInstance obj, string formatString) .Replace("{User}", (identity ?? (object)string.Empty).ToString()) .Replace("{Date}", DateTime.Today.ToShortDateString()) .Replace("{Time}", DateTime.Now.ToShortTimeString()); + Logging.Log.InfoFormat("Adding WF-Logentry: {0}", msg); var logEntry = ctx.Create(); logEntry.Message = msg; logEntry.Identity = identity; diff --git a/Zetbox.Workflow.Server/SchedulerService.cs b/Zetbox.Workflow.Server/SchedulerService.cs index c249be8..50f3812 100644 --- a/Zetbox.Workflow.Server/SchedulerService.cs +++ b/Zetbox.Workflow.Server/SchedulerService.cs @@ -97,6 +97,7 @@ private void OnTimer(object state) .Take(MAX_ITEMS_PER_BATCH) .ToList(); if (nextSchedulerEntries.Count == 0) break; + Logging.Server.InfoFormat("Found {0} SchedulerEntries", nextSchedulerEntries.Count); foreach (var entry in nextSchedulerEntries) { lock (_lock) @@ -116,6 +117,10 @@ private void OnTimer(object state) .Where(ad => ad.IsRecurrent) .Where(ad => ad.InvokeAction == localEntry.Action) .ToList(); + Logging.Server.InfoFormat(" processing wf instance.state '{0}.{1}', {2} actions", + localEntry.State.Instance, + localEntry.State.ToString(), + scheduledActions.Count); foreach(var sAction in scheduledActions) { sAction.Action.Execute(sAction, localEntry.State);