Log events on RelayCommand vs RoutedCommand

Question

I have the following problem:

I need to be able to log commands bound to the buttons in my code. The system that I am working on has all it's buttons as RelayCommand. I have found a website that explains how to do this, but with RoutedCommands. The link is a the button of the post. Here is an example of how it works with RoutedCommands:

public partial class Window1 : System.Windows.Window
            {
                public Window1()
                {
                    InitializeComponent();

                    CommandManager.AddPreviewExecutedHandler(this, this.OnPreviewCommandExecuted);

                    CommandManager.AddCanExecuteHandler(this, this.OnCommandCanExecute);
                }

                void OnPreviewCommandExecuted(object sender, ExecutedRoutedEventArgs e)
                {
                    StringBuilder msg = new StringBuilder();
                    msg.AppendLine();

                    RoutedCommand cmd = e.Command as RoutedCommand;
                    string name = cmd == null ? "n/a" : cmd.Name;

                    msg.AppendFormat("  Name={0}; Parameter={1}; Source={2}", name, e.Parameter, e.Source);
                    msg.AppendLine();

                    Logger.Log(msg.ToString());
                }

                void OnCommandCanExecute(object sender, CanExecuteRoutedEventArgs e)
                {
                    // For the sake of this demo, just allow all
                    // commands to be executed.
                    e.CanExecute = true;
                }
            }
        }

My problem is this doesn't work with RelayCommands and I can't afford to change all the RelayCommands to RoutedCommands.

Does anybody know how this can be implemented with RelayCommands?

Here is a example of a RelayCommand in my code:

            private RelayCommand _closePopupCommand = new RelayCommand(() => Window.PopUpViewModel = null);
            public RelayCommand ClosePopupCommand
            {
                get => _closePopupCommand;
                set
                {
                    _closePopupCommand = value;
                    RaisePropertyChanged();
                }
            }

And a the codebehind to route events:

            public readonly RoutedEvent ConditionalClickEvent = EventManager.RegisterRoutedEvent("test", RoutingStrategy.Direct, typeof(RoutedEventHandler), typeof(Button));

Link to the website that implements RoutedCommands: https://joshsmithonwpf.wordpress.com/2007/10/25/logging-routed-commands/

I have tried with RelayCommands but they don't seem to have the same functionality as RoutedCommands I think it has to do with the RoutedEvents, that RoutedCommands binds. From what I see, there are 3 options:

1. Can't be done
2. I will have to change the RelayCommands to RoutedCommands
3. Use something like RegisterEventHandlers

Answer 1

Perhaps listening to the Click event will suit you?

        public MainWindow()
        {
            InitializeComponent();

            AddHandler(ButtonBase.ClickEvent, (RoutedEventHandler)OnClickLoger, true);

        }

        private void OnClickLoger(object sender, RoutedEventArgs e)
        {
            if (e.Source is ButtonBase button && button.Command is ICommand command)
            {
                if (command is RoutedCommand routedCommand)
                {
                    Debug.WriteLine($"Button: Name=\"{button.Name}\"; RoutedCommand=\"{routedCommand.Name}\"; CommandParameter={button.CommandParameter} ");
                }
                else
                {
                    var be = button.GetBindingExpression(ButtonBase.CommandProperty);
                    if (be is null)
                    {
                        Debug.WriteLine($"Button: Name=\"{button.Name}\"; Command=\"{command}\"; CommandParameter={button.CommandParameter} ");
                    }
                    else
                    {
                        Debug.WriteLine($"Button: Name=\"{button.Name}\"; Command Path=\"{be.ParentBinding.Path.Path}\"; CommandParameter={button.CommandParameter} ");
                    }
                }
            }
        }

Answer 2

You can add a logger output in the execute command handler that you registered with the RelayCommand. You can even move the logging directly to the RelayCommand.Execute method.

Depending on what context related info you want to log you might decide to implement a helper class that can operate in the context of the view, for example to collect info about the command source (usually a control) that has invoked the command.

The following example misses unregister methods to unsubscribe from events. You need to add them to allow unregistering from event to prevent memory leaks. This is not relevant for class handler but important for instance handlers (like for the RelayCommand.Executed event).

1. In order to provide the same information that a RoutedCommand provides e.g. source, target and command name, you need to extend your RelayCommand. In order to avoid breaking existing code by introducing a derived type, you could modify the RelayCommand sources directly.

   The following command (taken from Microsoft Docs: Relaying Command Logic) exposes a Name and a Target property and a Executed event. The two properties are optional, but recommended if you want to provide information like a command name and the command target (the type that executes the command handlers, for example a view model class):

RelayCommand.cs

public class RelayCommand : ICommand
{
  /**** Added members ****/
  public class ExecutedEventArgs : EventArgs
  {
    public ExecutedEventArgs(object commandParameter)
    {
      this.CommandParameter = commandParameter;
    }

    public object CommandParameter { get; }
  }

  public string Name { get; }
  public object Target => this._execute.Target;
  public event EventHandler<ExecutedEventArgs> Executed;

  // Constructor to set the command name
  public RelayCommand(string commandName, Action<object> execute, Predicate<object> canExecute)
  {
    this.Name = commandName;

    if (execute == null)
      throw new ArgumentNullException("execute");
    _execute = execute;
    _canExecute = canExecute;
  }

  // Invoked by ICommand.Execute (added below)
  protected virtual void OnExecuted(object commandParameter)
    => this.Executed?.Invoke(this, new ExecutedEventArgs(commandParameter));

  /**** End added members ****/

  #region Fields 
  readonly Action<object> _execute;
  readonly Predicate<object> _canExecute;
  private readonly Action<string> _loggerDelegate;
  #endregion // Fields 
  #region Constructors 
  public RelayCommand(Action<object> execute)
    : this(string.Empty, execute, null)
  { }

  public RelayCommand(Action<object> execute, Predicate<object> canExecute)
    : this(string.Empty, execute, canExecute)
  { }
  #endregion // Constructors 
  #region ICommand Members 
  public bool CanExecute(object parameter)
  {
    return _canExecute == null ? true : _canExecute(parameter);
  }

  public event EventHandler CanExecuteChanged
  {
    add { CommandManager.RequerySuggested += value; }
    remove { CommandManager.RequerySuggested -= value; }
  }

  public void Execute(object parameter)
  {
    _execute(parameter);
    OnExecuted(parameter);
  }
  #endregion // ICommand Members 
}

2. Then create a data type to carry the collected command context info:

CommandContext.cs

public class CommandContext
{
  public Type CommandSource { get; }
  public Type CommandTarget { get; }
  public string CommandName { get; }
  public Type Command { get; }
  public object CommandParameter { get; }
  public string CommandSourceElementName { get; }
  public DateTime Timestamp { get; }

  public CommandContext(string commandName, Type command, object commandParameter, Type commandSource, string sourceElementName, Type commandTarget, DateTime timestamp)
  {
    this.CommandSource = commandSource;
    this.CommandTarget = commandTarget;
    this.CommandName = commandName;
    this.Command = command;
    this.CommandParameter = commandParameter;
    this.CommandSourceElementName = sourceElementName;
    this.Timestamp = timestamp;
  }
}

3. Create the actual helper class CommandContextTracer that provides the command's execution context.

   The idea is to register a global RoutedCommand handler to trace RoutedCommand invocations and to collect context information.
   For "normal" ICommand implementations we register a global (class level) ButtonBase.ClickEvent handler (assuming that all commands are invoked by a ButtonBase.

   You can of course extend this class to provide a method to register any command explicitly or to make the triggering event dynamic (e.g. to listen to any other event than the Click event).

   The CommandContextTracer will accept a Action<CommandContext> delegate that it invokes on command execution.

   For simplicity the class CommandContextTracer is a static class. In case you use dependency injection, I highly recommend to convert the static class to a normal class with instance members. Then inject a shared instance to your views (or classes that define commands in general). While views i.e. types that extend UIElement, can register anonymously, other classes must register their commands explicitly if the command is not invoked by a UIElement.

CommandContextTracer.cs

public static class CommandContextTracer
{
  private static Dictionary<object, Action<CommandContext>> LoghandlerTable { get; } = new Dictionary<object, Action<CommandContext>>();

  public static void RegisterCommandScopeElement(UIElement commandScopeElement, Action<CommandContext> logHandler)
  {
    if (!LoghandlerTable.TryAdd(commandScopeElement, logHandler))
    {
      return;
    }

    CommandManager.AddPreviewExecutedHandler(commandScopeElement, OnExecutingCommand);
    EventManager.RegisterClassHandler(commandScopeElement.GetType(), ButtonBase.ClickEvent, new RoutedEventHandler(OnEvent), true);
  }

  // Use this method to trace a command that is not invoked by a control.
  // TODO::Provide an Unregister(RelayCommand) method
  public static void RegisterRelayCommandInNonUiContext(RelayCommand relayCommand, Action<CommandContext> logHandler)
  {
    if (!LoghandlerTable.TryAdd(relayCommand, logHandler))
    {
      return;
    }

    relayCommand.Executed += OnNonUiRelayCommandExecuted;
  }

  private static void OnNonUiRelayCommandExecuted(object sender, RelayCommand.ExecutedEventArgs e)
  {
    var command = sender as RelayCommand;
    CommandContext context = new CommandContext(command.Name, command.GetType(), e.CommandParameter, null, string.Empty, command.Target.GetType());
    WriteContext(command, context);
  }

  private static void OnExecutingCommand(object sender, ExecutedRoutedEventArgs e)
  {
    if (e.Source is not ICommandSource commandSource)
    {
      return;
    }

    CommandContext context = CreateCommandContext(e, commandSource);
    WriteContext(sender, context);
  }

  private static void OnEvent(object sender, RoutedEventArgs e)
  {
    if (e.Source is not ICommandSource commandSource
      || commandSource.Command is RoutedCommand)
    {
      return;
    }

    CommandContext context = CreateCommandContext(e, commandSource);
    WriteContext(sender, context);
  }

  private static CommandContext CreateCommandContext(RoutedEventArgs e, ICommandSource commandSource)
  {
    string elementName = e.Source is FrameworkElement frameworkElement
      ? frameworkElement.Name
      : string.Empty;

    string commandName = commandSource.Command switch
    {
      RelayCommand relayCommand => relayCommand.Name,
      RoutedCommand routedCommand => routedCommand.Name,
      _ => string.Empty
    };

    Type? commandTarget = commandSource.Command switch
    {
      RelayCommand relayCommand => relayCommand.Target?.GetType(),
      RoutedCommand routedCommand => commandSource.CommandTarget?.GetType(),
      _ => null
    };

    return new CommandContext(
      commandName,
      commandSource.Command.GetType(),
      commandSource.CommandParameter,
      commandSource.GetType(),
      elementName,
      commandTarget,
      DateTime.Now);
  }

  public static void WriteContext(object contextScopeElement, CommandContext context)
    => LoghandlerTable[contextScopeElement].Invoke(context);
}

Usage example

MainWindow.xaml.cs
First scenario will log all command invocations where the source is a control:

partial class MainWindow : Window
{
  public static RoutedCommand NextPageCommand { get; } = new RoutedCommand("NextPageCommand", typeof(MainWindow));

  public MainWindow()
  {
    InitializeComponent();
    this.DataContext = new TestViewModel();

    // Trace RoutedCommands and other ICommand
    CommandContextTracer.RegisterCommandScopeElement(this, WriteCommandContextToLogger);
  }
  
  // The actual log handler
  private void WriteCommandContextToLogger(CommandContext commandContext)
  {
    string message = $"[{commandContext.Timestamp}] CommandName={commandContext.CommandName}; Command={commandContext.Command}; Parameter={commandContext.CommandParameter}; Source={commandContext.CommandSource}; SourceElementName={commandContext.CommandSourceElementName}; Target={commandContext.CommandTarget}";

    Logger.Log(message);
    // Debug.WriteLine(message);
  }
}

TextViewModel.cs
Second scenario logs command invocations where the source is not a control.
It also shows how to create an instance of the modified RelayCommand:

public class TestViewModel : INotifyPropertyChanged
{
  public RelayCommand TestCommand { get; }

  public TestViewModel()
  {
    this.TestCommand = new RelayCommand(nameof(this.TestCommand, ExecuteTestCommand);

    // Explicit command tracing. Only use when the command is not invoked by a control (non UI scenario)
    CommandContextTracer.RegisterRelayCommandInNonUiContext(this.TestCommand, WriteCommandContextToLogger);
  }

  private void WriteCommandContextToLogger(CommandContext commandContext)
  {
    string message = $"<From TestViewModel>[{commandContext.Timestamp}] CommandName={commandContext.CommandName}; Command={commandContext.Command}; Parameter={commandContext.CommandParameter}; Source={commandContext.CommandSource}; SourceElementName={commandContext.CommandSourceElementName}; Target={commandContext.CommandTarget}";

    Logger.Log(message);
    // Debug.WriteLine(message);
  }
}

MainWindow.xaml

<Window>
  <StackPanel>
    <Button x:Name="RelayCommandTestButton"
            Content="RelayCommand"
            Command="{Binding TestCommand}"
            CommandParameter="1" />
    <Button x:Name="RoutedCommandTestButton"
            Content="RoutedCommand"
            Command="{x:Static local:MainWindow.NextPageCommand}"
            CommandParameter="2" />
  </StackPanel>
</Window>

Log message

"[01/01/2022 00:00:00] CommandName=TestCommand; Command=Net.Wpf.RelayCommand; Parameter=1; Source=System.Windows.Controls.Button; SourceElementName=RelayCommandTestButton; Target=Net.Wpf.TestViewModel"  
"[01/01/2022 00:00:00] CommandName=NextPageCommand; Command=System.Windows.Input.RoutedCommand; Parameter=2; Source=System.Windows.Controls.Button; SourceElementName=RoutedCommandTestButton; Target="  
"<From TestViewModel>[01/01/2022 00:00:00] CommandName=TestCommand; Command=Net.Wpf.RelayCommand; Parameter=2; Source=unknown; SourceElementName=; Target=Net.Wpf.TestViewModel"